From 2e8c69780330385d094de5f56946759cda175afc Mon Sep 17 00:00:00 2001 From: adham90 Date: Wed, 2 Sep 2026 13:09:38 +0300 Subject: [PATCH] perf(dashboard): fix executions list slowness and 500s, sweep other pages The executions list ran 12 queries per view, four of them full table scans, and preloaded every execution_details payload column (prompts, response JSON) for the page just to render error_message on error rows. Summing on an includes() relation also joined children without DISTINCT, inflating the cost/token totals once per child execution. - Add Execution#error_detail (id, execution_id, error_message only) and preload it on every list path: executions index, agent show table, dashboard recent strip, CSV export - Execution.totals: count + both sums in one query, shared with pagination - Execution.stats_for in one query (was 8, called once per agent on the agents index); cache_hit_rate / streaming_rate in one query each; avg_time_to_first_token averaged in SQL instead of plucking metadata - Cache the DISTINCT agent/model/tenant dropdown scans for 5 minutes via shared ApplicationController helpers; cache AgentRegistry.execution_agents - Agent show: DISTINCT on the model/temperature filter pluck - Requests index: one stats query shared with pagination; STRING_AGG on PostgreSQL where GROUP_CONCAT does not exist - Paginatable: accept total_count:, load the page relation - Add [:parent_execution_id, :created_at] index and upgrade migration - spec/support/sql_capture.rb and query-shape regression specs Co-Authored-By: Claude Fable 5.1 --- .../concerns/ruby_llm/agents/paginatable.rb | 9 +- .../ruby_llm/agents/agents_controller.rb | 17 +-- .../ruby_llm/agents/analytics_controller.rb | 5 +- .../ruby_llm/agents/dashboard_controller.rb | 7 +- .../ruby_llm/agents/executions_controller.rb | 53 ++------- .../ruby_llm/agents/requests_controller.rb | 37 ++++--- app/models/ruby_llm/agents/execution.rb | 15 ++- .../ruby_llm/agents/execution/analytics.rb | 102 ++++++++++++----- .../ruby_llm/agents/agent_registry.rb | 8 +- .../2026-09-01-executions-list-performance.md | 104 ++++++++++++++++++ ..._root_execution_list_index_migration.rb.tt | 16 +++ .../ruby_llm_agents/templates/migration.rb.tt | 1 + .../ruby_llm_agents/upgrade_generator.rb | 19 ++++ lib/ruby_llm/agents/rails/engine.rb | 48 +++++++- spec/controllers/agents_controller_spec.rb | 31 ++++++ spec/controllers/dashboard_controller_spec.rb | 13 +++ .../controllers/executions_controller_spec.rb | 40 +++++++ spec/controllers/executions_export_spec.rb | 33 ++++++ spec/controllers/requests_controller_spec.rb | 12 ++ spec/dummy/db/schema.rb | 1 + spec/models/execution/analytics_spec.rb | 44 ++++++++ spec/support/sql_capture.rb | 23 ++++ 22 files changed, 530 insertions(+), 108 deletions(-) create mode 100644 changelog/2026-09-01-executions-list-performance.md create mode 100644 lib/generators/ruby_llm_agents/templates/add_root_execution_list_index_migration.rb.tt create mode 100644 spec/controllers/executions_export_spec.rb create mode 100644 spec/support/sql_capture.rb diff --git a/app/controllers/concerns/ruby_llm/agents/paginatable.rb b/app/controllers/concerns/ruby_llm/agents/paginatable.rb index f855a448..0187e821 100644 --- a/app/controllers/concerns/ruby_llm/agents/paginatable.rb +++ b/app/controllers/concerns/ruby_llm/agents/paginatable.rb @@ -22,6 +22,7 @@ module Paginatable # @param scope [ActiveRecord::Relation] The scope to paginate # @param ordered [Boolean] Whether to apply default descending order (default: true) # @param sort_params [Hash, nil] Optional custom sort parameters with :column and :direction + # @param total_count [Integer, nil] Precomputed row count; skips the COUNT query # @return [Hash] Contains :records and :pagination keys # @option return [ActiveRecord::Relation] :records Paginated records # @option return [Hash] :pagination Pagination metadata @@ -29,7 +30,7 @@ module Paginatable # - :per_page [Integer] Records per page # - :total_count [Integer] Total record count # - :total_pages [Integer] Total page count - def paginate(scope, ordered: true, sort_params: nil) + def paginate(scope, ordered: true, sort_params: nil, total_count: nil) page = [(params[:page] || 1).to_i, 1].max per_page = RubyLLM::Agents.configuration.per_page offset = (page - 1) * per_page @@ -41,10 +42,12 @@ def paginate(scope, ordered: true, sort_params: nil) elsif ordered scope = scope.order("#{table_name}.created_at DESC") end - total_count = scope.count + total_count ||= scope.count { - records: scope.offset(offset).limit(per_page), + # Loaded eagerly: the views call `records.empty?` before iterating, + # which on an unloaded relation costs a second SELECT. + records: scope.offset(offset).limit(per_page).load, pagination: { current_page: page, per_page: per_page, diff --git a/app/controllers/ruby_llm/agents/agents_controller.rb b/app/controllers/ruby_llm/agents/agents_controller.rb index 22fd9bb4..cb6f2de5 100644 --- a/app/controllers/ruby_llm/agents/agents_controller.rb +++ b/app/controllers/ruby_llm/agents/agents_controller.rb @@ -174,11 +174,13 @@ def load_agent_stats # # @return [void] def load_filter_options - # Single query to get all filter options (fixes N+1) + # Single DISTINCT query for all filter options. Without DISTINCT this + # plucked one row per execution the agent has ever run. base = tenant_scoped_executions.by_agent(@agent_type) filter_data = base .where.not(model_id: nil) .or(base.where.not(temperature: nil)) + .distinct .pluck(:model_id, :temperature) @models = filter_data.map(&:first).compact.uniq.sort @@ -192,15 +194,14 @@ def load_filter_options # @return [void] def load_filtered_executions base_scope = build_filtered_scope - result = paginate(base_scope) + @filter_stats = base_scope.totals + + # error_detail: the table renders error_message per row, and the full + # detail row carries every prompt and response payload. + result = paginate(base_scope.preload(:error_detail), + total_count: @filter_stats[:total_count]) @executions = result[:records] @pagination = result[:pagination] - - @filter_stats = { - total_count: result[:pagination][:total_count], - total_cost: base_scope.sum(:total_cost), - total_tokens: base_scope.sum(:total_tokens) - } end # Builds a filtered scope for the current agent's executions diff --git a/app/controllers/ruby_llm/agents/analytics_controller.rb b/app/controllers/ruby_llm/agents/analytics_controller.rb index 6353558f..28c7b73d 100644 --- a/app/controllers/ruby_llm/agents/analytics_controller.rb +++ b/app/controllers/ruby_llm/agents/analytics_controller.rb @@ -106,9 +106,8 @@ def prior_period_scope(scope) # ── Filters ────────────────────────── def load_filter_options - base = tenant_scoped_executions - @available_agents = base.where.not(agent_type: nil).distinct.pluck(:agent_type).sort - @available_models = base.where.not(model_id: nil).distinct.pluck(:model_id).sort + @available_agents = available_agent_types + @available_models = available_model_ids @available_tenants = if tenant_filter_enabled? && Tenant.table_exists? Tenant.pluck(:tenant_id, :name).map { |tid, name| [tid, name.presence || tid] }.sort_by(&:last) else diff --git a/app/controllers/ruby_llm/agents/dashboard_controller.rb b/app/controllers/ruby_llm/agents/dashboard_controller.rb index 958b6327..d8fb6eed 100644 --- a/app/controllers/ruby_llm/agents/dashboard_controller.rb +++ b/app/controllers/ruby_llm/agents/dashboard_controller.rb @@ -24,7 +24,7 @@ def index base_scope = tenant_scoped_executions @now_strip = build_now_strip(base_scope) @critical_alerts = load_critical_alerts(base_scope) - @recent_executions = base_scope.includes(:detail).recent(10) + @recent_executions = base_scope.preload(:error_detail).recent(10) @agent_stats = build_agent_comparison(base_scope) @top_errors = build_top_errors(base_scope) @tenant_budget = load_tenant_budget(base_scope) @@ -217,10 +217,7 @@ def load_budget_status def load_open_breakers open_breakers = [] - # Get all agents from execution history - agent_types = tenant_scoped_executions.distinct.pluck(:agent_type) - - agent_types.each do |agent_type| + available_agent_types.each do |agent_type| # Get the agent class if available agent_class = AgentRegistry.find(agent_type) next unless agent_class diff --git a/app/controllers/ruby_llm/agents/executions_controller.rb b/app/controllers/ruby_llm/agents/executions_controller.rb index 899cf6b0..78c00b38 100644 --- a/app/controllers/ruby_llm/agents/executions_controller.rb +++ b/app/controllers/ruby_llm/agents/executions_controller.rb @@ -39,7 +39,7 @@ def index # # @return [void] def show - @execution = tenant_scoped_executions.includes(:detail, :child_executions).find(params[:id]) + @execution = tenant_scoped_executions.includes(:detail).find(params[:id]) end # Handles filter search requests via Turbo Stream @@ -83,7 +83,7 @@ def export self.response_body = Enumerator.new do |yielder| yielder << CSV.generate_line(CSV_COLUMNS) - filtered_executions.find_each(batch_size: 1000) do |execution| + filtered_executions.preload(:error_detail).find_each(batch_size: 1000) do |execution| yielder << generate_csv_row(execution) end end @@ -124,26 +124,6 @@ def load_filter_options @statuses = Execution.statuses.keys end - # Returns distinct agent types from execution history - # - # Memoized to avoid duplicate queries within a request. - # Uses tenant_scoped_executions to respect multi-tenancy filtering. - # - # @return [Array] Agent type names - def available_agent_types - @available_agent_types ||= tenant_scoped_executions.distinct.pluck(:agent_type) - end - - # Returns distinct model IDs from execution history - # - # Memoized to avoid duplicate queries within a request. - # Uses tenant_scoped_executions to respect multi-tenancy filtering. - # - # @return [Array] Model IDs - def available_model_ids - @available_model_ids ||= tenant_scoped_executions.where.not(model_id: nil).distinct.pluck(:model_id).sort - end - # Loads paginated executions and associated statistics # # Sets @executions, @pagination, @sort_params, and @filter_stats instance variables @@ -152,22 +132,17 @@ def available_model_ids # @return [void] def load_executions_with_stats @sort_params = parse_sort_params - result = paginate(filtered_executions, sort_params: @sort_params) + scope = filtered_executions + + # One aggregate query for the stats strip; its count is reused for + # pagination, so the page costs one aggregate query instead of four. + @filter_stats = scope.totals + + result = paginate(scope.preload(:error_detail), + sort_params: @sort_params, + total_count: @filter_stats[:total_count]) @executions = result[:records] @pagination = result[:pagination] - load_filter_stats - end - - # Calculates aggregate statistics for the current filter - # - # @return [void] - def load_filter_stats - scope = filtered_executions - @filter_stats = { - total_count: scope.count, - total_cost: scope.sum(:total_cost) || 0, - total_tokens: scope.sum(:total_tokens) || 0 - } end # Builds a filtered execution scope based on request params @@ -212,11 +187,7 @@ def filtered_executions scope = scope.where("attempts_count > 1") if params[:has_retries].present? # Only show root executions - children are nested under parents - scope = scope.where(parent_execution_id: nil) - - # Eager load children for grouping and detail for error_message, which - # the list renders per row (otherwise an N+1 on error rows). - scope.includes(:child_executions, :detail) + scope.where(parent_execution_id: nil) end # Checks whether turbo-rails is available in the host application diff --git a/app/controllers/ruby_llm/agents/requests_controller.rb b/app/controllers/ruby_llm/agents/requests_controller.rb index 987be19d..eed2884c 100644 --- a/app/controllers/ruby_llm/agents/requests_controller.rb +++ b/app/controllers/ruby_llm/agents/requests_controller.rb @@ -28,8 +28,8 @@ def index "MIN(started_at) AS started_at", "MAX(completed_at) AS completed_at", "SUM(duration_ms) AS total_duration_ms", - "GROUP_CONCAT(DISTINCT agent_type) AS agent_types_list", - "GROUP_CONCAT(DISTINCT status) AS statuses_list", + "#{distinct_list_sql("agent_type")} AS agent_types_list", + "#{distinct_list_sql("status")} AS statuses_list", "MAX(created_at) AS latest_created_at" ) .group(:request_id) @@ -38,16 +38,16 @@ def index days = params[:days].to_i scope = scope.where("created_at >= ?", days.days.ago) if days > 0 - result = paginate_requests(scope) + # One query for the distinct request count and total cost; the count + # is shared with pagination instead of being run a second time. + total_requests, total_cost = Execution + .where.not(request_id: [nil, ""]) + .pick(Arel.sql("COUNT(DISTINCT request_id)"), Arel.sql("COALESCE(SUM(total_cost), 0)")) + @stats = {total_requests: total_requests.to_i, total_cost: (total_cost || 0).to_d.round(6)} + + result = paginate_requests(scope, total_count: @stats[:total_requests]) @requests = result[:records] @pagination = result[:pagination] - - # Stats - total_scope = Execution.where.not(request_id: [nil, ""]) - @stats = { - total_requests: total_scope.distinct.count(:request_id), - total_cost: total_scope.sum(:total_cost) || 0 - } end # Shows a single tracked request with all its executions @@ -90,15 +90,20 @@ def sanitize_sort_column(column) ALLOWED_SORT_COLUMNS.include?(column) ? column : "latest_created_at" end - def paginate_requests(scope) + # Comma-separated DISTINCT values of a column per group. + # GROUP_CONCAT exists on SQLite and MySQL; PostgreSQL spells it STRING_AGG. + def distinct_list_sql(column) + if Execution.connection.adapter_name.downcase.include?("postg") + "STRING_AGG(DISTINCT #{column}, ',')" + else + "GROUP_CONCAT(DISTINCT #{column})" + end + end + + def paginate_requests(scope, total_count:) page = [(params[:page] || 1).to_i, 1].max per_page = RubyLLM::Agents.configuration.per_page - total_count = Execution - .where.not(request_id: [nil, ""]) - .distinct - .count(:request_id) - sorted = scope.order("#{@sort_column} #{@sort_direction.upcase}") offset = (page - 1) * per_page diff --git a/app/models/ruby_llm/agents/execution.rb b/app/models/ruby_llm/agents/execution.rb index 44456530..c484617f 100644 --- a/app/models/ruby_llm/agents/execution.rb +++ b/app/models/ruby_llm/agents/execution.rb @@ -74,6 +74,18 @@ class Execution < ::ActiveRecord::Base has_one :detail, class_name: "RubyLLM::Agents::ExecutionDetail", foreign_key: :execution_id, dependent: :destroy + # Same row as :detail, but selecting only error_message. + # + # List and CSV views read nothing but the error message, while the full + # detail row carries prompts and response JSON that routinely run to + # hundreds of kilobytes each. Preloading :detail for a page of rows drags + # all of that into memory; preloading :error_detail costs a few bytes per + # row. Never use this association for anything but error_message — the + # other attributes are not selected and will raise. + has_one :error_detail, -> { select(:id, :execution_id, :error_message) }, + class_name: "RubyLLM::Agents::ExecutionDetail", + foreign_key: :execution_id, inverse_of: false + # Individual tool call records (real-time tracking) has_many :tool_executions, class_name: "RubyLLM::Agents::ToolExecution", foreign_key: :execution_id, dependent: :destroy @@ -94,7 +106,8 @@ class Execution < ::ActiveRecord::Base # # @return [String, nil] def error_message - detail&.error_message || metadata&.dig("error_message") + row = association(:detail).loaded? ? detail : error_detail + row&.error_message || metadata&.dig("error_message") end # Validations diff --git a/app/models/ruby_llm/agents/execution/analytics.rb b/app/models/ruby_llm/agents/execution/analytics.rb index cfd4d8af..f02452b2 100644 --- a/app/models/ruby_llm/agents/execution/analytics.rb +++ b/app/models/ruby_llm/agents/execution/analytics.rb @@ -79,8 +79,22 @@ def cost_by_agent(period: :today) # @return [Hash] Statistics including count, costs, tokens, duration, rates def stats_for(agent_type, period: :today) scope = by_agent(agent_type).public_send(period) - count = scope.count - total_cost = scope.total_cost_sum || 0 + + # One aggregate query. The agents index calls this once per agent, + # so the eight separate count/sum/avg scans it used to run became + # eight full scans of that agent's history per row. + count, cost, tokens, avg_tok, avg_dur, successful, failed = scope.pick( + Arel.sql("COUNT(*)"), + Arel.sql("COALESCE(SUM(total_cost), 0)"), + Arel.sql("COALESCE(SUM(total_tokens), 0)"), + Arel.sql("AVG(total_tokens)"), + Arel.sql("AVG(duration_ms)"), + Arel.sql("SUM(CASE WHEN status = 'success' THEN 1 ELSE 0 END)"), + Arel.sql("SUM(CASE WHEN status IN ('error', 'timeout') THEN 1 ELSE 0 END)") + ) + + count = count.to_i + total_cost = (cost || 0).to_d.round(6) { agent_type: agent_type, @@ -88,14 +102,27 @@ def stats_for(agent_type, period: :today) count: count, total_cost: total_cost, avg_cost: (count > 0) ? (total_cost / count).round(6) : 0, - total_tokens: scope.total_tokens_sum || 0, - avg_tokens: scope.avg_tokens&.round || 0, - avg_duration_ms: scope.avg_duration&.round || 0, - success_rate: calculate_success_rate(scope), - error_rate: calculate_error_rate(scope) + total_tokens: tokens.to_i, + avg_tokens: avg_tok&.round || 0, + avg_duration_ms: avg_dur&.round || 0, + success_rate: (count > 0) ? (successful.to_f / count * 100).round(2) : 0.0, + error_rate: (count > 0) ? (failed.to_f / count * 100).round(2) : 0.0 } end + # Count, cost and token totals for the current scope in one query + # + # @return [Hash] :total_count, :total_cost (BigDecimal), :total_tokens + def totals + count, cost, tokens = pick( + Arel.sql("COUNT(*)"), + Arel.sql("COALESCE(SUM(total_cost), 0)"), + Arel.sql("COALESCE(SUM(total_tokens), 0)") + ) + + {total_count: count.to_i, total_cost: (cost || 0).to_d.round(6), total_tokens: tokens.to_i} + end + # Compares performance between two agent versions # Analyzes trends over a time period # @@ -470,36 +497,33 @@ def build_hourly_cost_data # # @return [Float] Percentage of executions that were cache hits (0.0-100.0) def cache_hit_rate - total = count - return 0.0 if total.zero? - - (cached.count.to_f / total * 100).round(1) + boolean_rate("cache_hit") end # Streaming execution rate percentage # # @return [Float] Percentage of executions that used streaming (0.0-100.0) def streaming_rate - total = count - return 0.0 if total.zero? - - (streaming.count.to_f / total * 100).round(1) + boolean_rate("streaming") end # Average time to first token for streaming executions # - # time_to_first_token_ms is stored in metadata JSON, so we use - # Ruby-level calculation instead of SQL aggregation. + # time_to_first_token_ms lives in the metadata JSON column, so the + # average is computed from a JSON extract in SQL rather than by + # loading every streaming execution's metadata into Ruby. # # @return [Integer, nil] Average TTFT in milliseconds, or nil if no data def avg_time_to_first_token - ttft_values = streaming - .where("metadata IS NOT NULL") - .pluck(:metadata) - .filter_map { |m| m&.dig("time_to_first_token_ms") } - return nil if ttft_values.empty? + ttft = if connection.adapter_name.downcase.include?("sqlite") + "json_extract(metadata, '$.time_to_first_token_ms')" + else + "(metadata->>'time_to_first_token_ms')::numeric" + end - (ttft_values.sum.to_f / ttft_values.size).round(0) + streaming.metadata_present("time_to_first_token_ms") + .pick(Arel.sql("AVG(#{ttft})")) + &.round end # Finish reason distribution @@ -790,16 +814,42 @@ def aggregated_chart_query(scope, granularity:) # SQL condition for boolean cache_hit column # + # @return [String] SQL condition fragment + def cache_hit_condition + true_condition("cache_hit") + end + + # SQL condition for a boolean column being true + # # SQLite stores booleans as 1/0, PostgreSQL as TRUE/FALSE. # + # @param column [String] Column name (internal literal, never user input) # @return [String] SQL condition fragment - def cache_hit_condition + def true_condition(column) if connection.adapter_name.downcase.include?("sqlite") - "cache_hit = 1" + "#{column} = 1" else - "cache_hit = TRUE" + "#{column} = TRUE" end end + + # Percentage of the current scope where a boolean column is true + # + # One query (count plus conditional sum) rather than a count of the + # scope followed by a count of the filtered scope. + # + # @param column [String] Column name (internal literal, never user input) + # @return [Float] 0.0-100.0 + def boolean_rate(column) + total, hits = pick( + Arel.sql("COUNT(*)"), + Arel.sql("SUM(CASE WHEN #{true_condition(column)} THEN 1 ELSE 0 END)") + ) + total = total.to_i + return 0.0 if total.zero? + + (hits.to_f / total * 100).round(1) + end end end end diff --git a/app/services/ruby_llm/agents/agent_registry.rb b/app/services/ruby_llm/agents/agent_registry.rb index bd7e7b1f..11274b90 100644 --- a/app/services/ruby_llm/agents/agent_registry.rb +++ b/app/services/ruby_llm/agents/agent_registry.rb @@ -183,9 +183,15 @@ def file_system_agents # Finds agent types from execution history # + # Cached briefly: this is an unbounded DISTINCT scan of the executions + # table, and it only exists to keep deleted agents visible, so a few + # minutes of staleness is invisible. + # # @return [Array] Agent class names with execution records def execution_agents - Execution.distinct.pluck(:agent_type).compact + Rails.cache.fetch(["ruby_llm_agents", "agent_registry", "execution_agents"], expires_in: 5.minutes) do + Execution.distinct.pluck(:agent_type).compact + end rescue => e Rails.logger.error("[RubyLLM::Agents] Error loading agents from executions: #{e.message}") [] diff --git a/changelog/2026-09-01-executions-list-performance.md b/changelog/2026-09-01-executions-list-performance.md new file mode 100644 index 00000000..4938afda --- /dev/null +++ b/changelog/2026-09-01-executions-list-performance.md @@ -0,0 +1,104 @@ +# Dashboard query performance (executions list and related pages) + +## Context + +`GET /agents/executions` was slow and returned 500s on large tables. Tracing +the request showed 12 SQL statements, four of them full scans of the executions +table, plus one query that loaded every large payload column for the visible +page: + +- `SELECT DISTINCT agent_type` and `SELECT DISTINCT model_id` — unbounded scans, + no usable index, run on every page view (a third, `DISTINCT tenant_id`, ran + from the filters partial). +- The same `COUNT(*)` twice: once in `Paginatable#paginate`, once in + `load_filter_stats`. +- `SUM(total_cost)` and `SUM(total_tokens)` over the filtered scope. Because + that scope carried `includes(:child_executions, :detail)`, ActiveRecord's + `has_include?` branch turned each sum into a `LEFT OUTER JOIN` across both + associations **without** `DISTINCT` — so the totals were also wrong, inflated + once per child execution. +- `includes(:child_executions)`, which nothing in the index views reads. +- `includes(:detail)`, which selects `system_prompt`, `user_prompt`, `response`, + `messages_summary`, `tool_calls` and `attempts` for every row on the page, so + the list could pull megabytes just to render `error_message` on error rows. + Image and audio agents store large payloads here; this is the memory blowup + behind the 500s. +- `executions.empty?` in the list partial issued an extra `SELECT 1` because the + paginated relation was returned unloaded. + +The main list query — `WHERE parent_execution_id IS NULL ORDER BY created_at +DESC` — also had no composite index, only the single-column ones. + +A sweep of the other dashboard pages found the same classes of problem: + +- **Agents index**: `Execution.stats_for` ran eight separate count/sum/avg + scans, and the index calls it once per agent (9 queries × N agents). +- **Agent show**: the model/temperature filter options were plucked **without + DISTINCT** (one row per execution the agent ever ran, into Ruby); + `avg_time_to_first_token` plucked every streaming execution's metadata JSON + to average one key; `cache_hit_rate` and `streaming_rate` each ran two + full-history counts; the executions table repeated the count + two sums and + had no preload, so error rows N+1'd on the full detail row. +- **Dashboard home**: the recent-executions strip preloaded full detail rows; + `load_open_breakers` and `AgentRegistry.execution_agents` each ran the + `DISTINCT agent_type` scan. +- **Analytics**: the same two DISTINCT scans for its dropdowns. +- **Requests index**: `COUNT(DISTINCT request_id)` ran twice (pagination and + stats strip) plus a separate `SUM`. It also used `GROUP_CONCAT`, which does + not exist on PostgreSQL, so the page 500'd there. +- **CSV export**: preloaded the full detail row for every execution in each + 1000-row batch. + +## Decision + +- Added `Execution#error_detail`: the same `has_one` row as `:detail` but + selecting only `id, execution_id, error_message`. `#error_message` uses it + unless `:detail` is already loaded. Every list-style view (executions index, + agent show table, dashboard recent strip, CSV export) preloads this instead + of the full detail row. `executions#show` keeps `includes(:detail)` and drops + the unused `:child_executions` preload. +- `Execution.totals` — count, cost and token sums for a scope in one `pick`, + matching the existing `aggregate_period_stats` pattern. Used by the + executions and agent show pages, with the count passed to + `paginate(total_count:)` so the page runs one aggregate query instead of + four. +- `Execution.stats_for` is one `pick` (was eight queries). `cache_hit_rate` and + `streaming_rate` are one query each via a shared `boolean_rate`. + `avg_time_to_first_token` averages a JSON extract in SQL (SQLite + `json_extract`, PostgreSQL `->>`) instead of loading metadata rows. +- The filter dropdown scans are cached for 5 minutes behind three helpers on + the engine's `ApplicationController` — `available_agent_types`, + `available_model_ids`, `available_tenants` — and shared by the executions, + dashboard and analytics controllers. `AgentRegistry.execution_agents` is + cached the same way with its own key. +- Agent show filter options use `DISTINCT`. +- Requests index computes its distinct count and cost sum in one `pick` shared + with pagination, and uses `STRING_AGG(DISTINCT …)` on PostgreSQL. +- `Paginatable#paginate` accepts `total_count:` and loads the page relation. +- New index `[:parent_execution_id, :created_at]`. + +Result on the executions list: 12 queries to 7 (3 of which are cached in +production), no large payload columns on the list path, and correct cost/token +totals. Agent show drops from ~30 queries to ~16 with no unbounded row loads; +agents index goes from 9 to 2 queries per agent. + +## Consequences + +- Host apps should run `rails generate ruby_llm_agents:upgrade` for the + `add_root_execution_list_index` migration. Existing installs work without it, + just without the index. +- A newly-seen agent type, model, or tenant takes up to 5 minutes to appear in + the filter dropdowns and, for history-only (deleted) agents, in the agents + list. Filtering by it via URL params works immediately. Apps whose + `Rails.cache` is a `NullStore` see no caching and no change. +- `@filter_stats[:total_cost]` and `[:total_tokens]` now exclude child + executions, matching the rows the list actually shows. Dashboards comparing + against the old (inflated) numbers will see them drop. +- `error_detail` selects three columns; reading any other attribute off it + raises `ActiveModel::MissingAttributeError`. Use `:detail` for anything else. +- The PostgreSQL branches (`STRING_AGG`, `->>` in the TTFT average) follow the + existing adapter idiom in this codebase but the test suite runs on SQLite + only, so they are not exercised by CI. +- `spec/support/sql_capture.rb` adds `capture_sql { }` for query-shape + regressions; the new specs pin query counts and assert that list paths never + load detail payload columns. diff --git a/lib/generators/ruby_llm_agents/templates/add_root_execution_list_index_migration.rb.tt b/lib/generators/ruby_llm_agents/templates/add_root_execution_list_index_migration.rb.tt new file mode 100644 index 00000000..4807aa1a --- /dev/null +++ b/lib/generators/ruby_llm_agents/templates/add_root_execution_list_index_migration.rb.tt @@ -0,0 +1,16 @@ +# frozen_string_literal: true + +# Migration to add the index behind the executions dashboard list +# +# The list page runs `WHERE parent_execution_id IS NULL ORDER BY created_at DESC` +# plus a COUNT over the same predicate. With only the single-column +# parent_execution_id and created_at indexes available, the planner has to pick +# one and filter the rest, which degrades to a sequential scan once child +# executions make up a meaningful share of the table. +class AddRootExecutionListIndex < ActiveRecord::Migration<%= migration_version %> + def change + add_index :ruby_llm_agents_executions, [:parent_execution_id, :created_at], + name: "idx_executions_parent_created_at", + if_not_exists: true + end +end diff --git a/lib/generators/ruby_llm_agents/templates/migration.rb.tt b/lib/generators/ruby_llm_agents/templates/migration.rb.tt index f0aa8954..db12e6ad 100644 --- a/lib/generators/ruby_llm_agents/templates/migration.rb.tt +++ b/lib/generators/ruby_llm_agents/templates/migration.rb.tt @@ -76,6 +76,7 @@ class CreateRubyLLMAgentsExecutions < ActiveRecord::Migration<%= migration_versi add_index :ruby_llm_agents_executions, :trace_id add_index :ruby_llm_agents_executions, :request_id add_index :ruby_llm_agents_executions, :parent_execution_id + add_index :ruby_llm_agents_executions, [:parent_execution_id, :created_at] add_index :ruby_llm_agents_executions, :root_execution_id add_index :ruby_llm_agents_executions, [:status, :created_at] add_index :ruby_llm_agents_executions, [:model_id, :status] diff --git a/lib/generators/ruby_llm_agents/upgrade_generator.rb b/lib/generators/ruby_llm_agents/upgrade_generator.rb index f74a5508..2e0b354b 100644 --- a/lib/generators/ruby_llm_agents/upgrade_generator.rb +++ b/lib/generators/ruby_llm_agents/upgrade_generator.rb @@ -117,6 +117,25 @@ def create_add_dashboard_performance_indexes_migration ) end + # Add the composite index behind the executions dashboard list + def create_add_root_execution_list_index_migration + unless table_exists?(:ruby_llm_agents_executions) + say_status :skip, "executions table does not exist yet", :yellow + return + end + + if index_exists?(:ruby_llm_agents_executions, [:parent_execution_id, :created_at]) + say_status :skip, "root execution list index already exists", :yellow + return + end + + say_status :upgrade, "Adding root execution list index", :blue + migration_template( + "add_root_execution_list_index_migration.rb.tt", + File.join(db_migrate_path, "add_root_execution_list_index.rb") + ) + end + # Create overrides table for dashboard-managed agent settings def create_overrides_migration if table_exists?(:ruby_llm_agents_overrides) diff --git a/lib/ruby_llm/agents/rails/engine.rb b/lib/ruby_llm/agents/rails/engine.rb index d8f4253e..17444920 100644 --- a/lib/ruby_llm/agents/rails/engine.rb +++ b/lib/ruby_llm/agents/rails/engine.rb @@ -168,10 +168,12 @@ def tenant_scoped_executions def available_tenants return @available_tenants if defined?(@available_tenants) - tenant_ids = RubyLLM::Agents::Execution - .where.not(tenant_id: nil) - .distinct - .pluck(:tenant_id) + tenant_ids = cached_filter_options(:tenant_ids) do + RubyLLM::Agents::Execution + .where.not(tenant_id: nil) + .distinct + .pluck(:tenant_id) + end names_by_id = RubyLLM::Agents::Tenant .where(tenant_id: tenant_ids) @@ -183,6 +185,44 @@ def available_tenants .sort_by { |t| t[:label].downcase } end helper_method :available_tenants + + # Distinct agent types in the tenant-scoped execution history, sorted + # + # @return [Array] + # @api public + def available_agent_types + cached_filter_options(:agent_types) do + tenant_scoped_executions.distinct.pluck(:agent_type).compact.sort + end + end + + # Distinct model IDs in the tenant-scoped execution history, sorted + # + # @return [Array] + # @api public + def available_model_ids + cached_filter_options(:model_ids) do + tenant_scoped_executions.where.not(model_id: nil).distinct.pluck(:model_id).sort + end + end + + # Caches one of the DISTINCT scans behind the dashboard's filter + # dropdowns. + # + # These scans have no WHERE clause an index can serve, so on a large + # executions table each is a full index scan, and several dashboard + # pages run two or three of them per request. The lists only change + # when a brand-new agent, model or tenant appears, so a short TTL is + # a fair trade: a new value shows up in the dropdown within five + # minutes, and filtering by it via URL params works immediately. + # + # @param key [Symbol] Which option list + # @return [Array] + # @api private + def cached_filter_options(key, &block) + Rails.cache.fetch(["ruby_llm_agents", "filter_options", key, current_tenant_id], + expires_in: 5.minutes, &block) + end end) end diff --git a/spec/controllers/agents_controller_spec.rb b/spec/controllers/agents_controller_spec.rb index 88c851bb..57cb5839 100644 --- a/spec/controllers/agents_controller_spec.rb +++ b/spec/controllers/agents_controller_spec.rb @@ -132,6 +132,37 @@ def show end describe "GET #show" do + # Regressions for the per-agent page's query shape. + context "query shape" do + before { create_list(:execution, 3, agent_type: "TestAgent") } + + it "loads filter options with a DISTINCT query instead of one row per execution" do + queries = capture_sql { get :show, params: {id: "TestAgent"} } + + expect(queries.grep(/SELECT DISTINCT .*"temperature"/)).to be_present + end + + it "runs one totals query and no standalone COUNT or SUM scans of the agent's history" do + queries = capture_sql { get :show, params: {id: "TestAgent"} } + + totals = queries.grep(/COUNT\(\*\), COALESCE\(SUM\(total_cost\), 0\), COALESCE\(SUM\(total_tokens\), 0\) FROM/) + expect(totals.size).to eq(1) + expect(queries.grep(/SELECT SUM\(/)).to be_empty + expect(queries.grep(/SELECT COUNT\(\*\) FROM/)).to be_empty + end + + it "preloads only error_message for the executions table" do + create(:execution, :failed, agent_type: "TestAgent") + + get :show, params: {id: "TestAgent"} + + row = assigns(:executions).find(&:status_error?) + expect(row.association(:error_detail)).to be_loaded + expect(row.error_detail.attributes.keys).to contain_exactly("id", "execution_id", "error_message") + expect(row.association(:detail)).not_to be_loaded + end + end + let!(:execution) { create(:execution, agent_type: "TestAgent") } it "returns http success" do diff --git a/spec/controllers/dashboard_controller_spec.rb b/spec/controllers/dashboard_controller_spec.rb index 38d35695..21907685 100644 --- a/spec/controllers/dashboard_controller_spec.rb +++ b/spec/controllers/dashboard_controller_spec.rb @@ -30,6 +30,19 @@ def index expect(assigns(:recent_executions)).to be_present end + # Regression: the recent-executions strip preloaded the full detail row + # (prompts, response JSON) for every entry to show an error message. + it "loads recent executions without the detail payload columns" do + create(:execution, :failed) + + get :index + + row = assigns(:recent_executions).to_a.first + expect(row.association(:error_detail)).to be_loaded + expect(row.error_detail.attributes.keys).to contain_exactly("id", "execution_id", "error_message") + expect(row.association(:detail)).not_to be_loaded + end + it "assigns @agent_stats" do get :index expect(assigns(:agent_stats)).to be_an(Array) diff --git a/spec/controllers/executions_controller_spec.rb b/spec/controllers/executions_controller_spec.rb index 4daaa16e..4a63bfaf 100644 --- a/spec/controllers/executions_controller_spec.rb +++ b/spec/controllers/executions_controller_spec.rb @@ -57,6 +57,46 @@ def search expect(assigns(:filter_stats)).to include(:total_count, :total_cost, :total_tokens) end + # Regression: filter_stats used to be summed on a scope carrying + # `includes(:child_executions, :detail)`. ActiveRecord turns a sum on an + # includes-relation into a LEFT JOIN without DISTINCT, so every child row + # multiplied its parent's cost and tokens into the total. + it "does not inflate @filter_stats when root executions have children" do + parent = create(:execution, input_cost: 1, output_cost: 0, total_tokens: 100) + 3.times { create(:execution, parent_execution_id: parent.id, input_cost: 5, output_cost: 0, total_tokens: 999) } + + get :index + + expect(assigns(:filter_stats)[:total_count]).to eq(1) + expect(assigns(:filter_stats)[:total_cost]).to eq(1) + expect(assigns(:filter_stats)[:total_tokens]).to eq(150) + end + + # Regression: the page ran four scans of the same filtered set — one COUNT + # for pagination, then COUNT + two SUMs for the stats strip. + it "aggregates count and sums in a single query" do + create_list(:execution, 3) + + aggregates = capture_sql { get :index }.grep(/COUNT\(\*\)|SUM\(/) + + expect(aggregates.size).to eq(1) + end + + # Regression: the list preloaded the full detail row to render error + # messages, dragging every prompt and response payload — hundreds of KB per + # row for image and audio agents — into memory for a whole page of results. + it "loads only error_message from execution details" do + create(:execution, :failed) + + get :index + + row = assigns(:executions).first + expect(row.association(:error_detail)).to be_loaded + expect(row.error_detail.attributes.keys).to contain_exactly("id", "execution_id", "error_message") + expect(row.association(:detail)).not_to be_loaded + expect(row.error_message).to eq("Something went wrong") + end + context "with agent_types filter" do before do create(:execution, agent_type: "AgentA") diff --git a/spec/controllers/executions_export_spec.rb b/spec/controllers/executions_export_spec.rb new file mode 100644 index 00000000..1a55553a --- /dev/null +++ b/spec/controllers/executions_export_spec.rb @@ -0,0 +1,33 @@ +# frozen_string_literal: true + +require "rails_helper" + +RSpec.describe "Executions CSV export", type: :request do + let(:export_path) { "/agents/executions/export" } + + it "streams one CSV row per root execution with its error message" do + create(:execution, :failed, agent_type: "ExportAgent") + create(:execution, agent_type: "ExportAgent") + + get export_path + + expect(response).to have_http_status(:ok) + expect(response.headers["Content-Type"]).to include("text/csv") + rows = CSV.parse(response.body, headers: true) + expect(rows.size).to eq(2) + expect(rows.map { |r| r["error_message"] }).to include("Something went wrong") + end + + # Regression: export preloaded the full detail row (prompts, response JSON) + # for every execution in each 1000-row batch just to read error_message. + it "preloads error messages narrowly, one query per batch" do + create_list(:execution, 3, :failed) + + detail_queries = capture_sql { get export_path } + .grep(/ruby_llm_agents_execution_details/) + + expect(detail_queries.size).to eq(1) + expect(detail_queries.first).to include("error_message") + expect(detail_queries.first).not_to include(".*") + end +end diff --git a/spec/controllers/requests_controller_spec.rb b/spec/controllers/requests_controller_spec.rb index 8247c5df..c9a5f4b1 100644 --- a/spec/controllers/requests_controller_spec.rb +++ b/spec/controllers/requests_controller_spec.rb @@ -18,6 +18,18 @@ expect(response).to have_http_status(:ok) end + # Regression: the distinct request count ran twice — once for pagination, + # once for the stats strip — alongside a separate SUM. + it "computes the stats strip and pagination count in one query" do + create(:execution, request_id: "req_001") + create(:execution, request_id: "req_002") + + queries = capture_sql { get engine_routes.url_helpers.requests_path } + + expect(queries.grep(/COUNT\(DISTINCT/).size).to eq(1) + expect(queries.grep(/SELECT SUM\(/)).to be_empty + end + it "lists requests grouped by request_id" do create(:execution, request_id: "req_001", agent_type: "AgentA") create(:execution, request_id: "req_001", agent_type: "AgentB") diff --git a/spec/dummy/db/schema.rb b/spec/dummy/db/schema.rb index 836dda82..8cd2d10c 100644 --- a/spec/dummy/db/schema.rb +++ b/spec/dummy/db/schema.rb @@ -78,6 +78,7 @@ add_index :ruby_llm_agents_executions, :trace_id add_index :ruby_llm_agents_executions, :request_id add_index :ruby_llm_agents_executions, :parent_execution_id + add_index :ruby_llm_agents_executions, [:parent_execution_id, :created_at] add_index :ruby_llm_agents_executions, :root_execution_id add_index :ruby_llm_agents_executions, [:status, :created_at] add_index :ruby_llm_agents_executions, [:model_id, :status] diff --git a/spec/models/execution/analytics_spec.rb b/spec/models/execution/analytics_spec.rb index d9228b9a..16b3da60 100644 --- a/spec/models/execution/analytics_spec.rb +++ b/spec/models/execution/analytics_spec.rb @@ -92,6 +92,50 @@ expect(stats[:avg_cost]).to eq(0) end end + + # Regression: the agents index calls this once per agent, and it used to + # run eight separate count/sum/avg scans of that agent's history each time. + it "runs a single aggregate query" do + expect(capture_sql { execution_class.stats_for("TestAgent", period: :today) }.size).to eq(1) + end + + it "computes rates from the same query" do + create(:execution, :failed) + create(:execution, :timeout) + + stats = execution_class.stats_for("TestAgent", period: :today) + expect(stats[:count]).to eq(4) + expect(stats[:success_rate]).to eq(50.0) + expect(stats[:error_rate]).to eq(50.0) + end + end + + describe ".avg_time_to_first_token" do + it "returns nil when no streaming execution recorded a value" do + create(:execution, streaming: true, metadata: {}) + expect(execution_class.avg_time_to_first_token).to be_nil + end + + it "averages the value from metadata across streaming executions only" do + create(:execution, streaming: true, metadata: {time_to_first_token_ms: 100}) + create(:execution, streaming: true, metadata: {time_to_first_token_ms: 300}) + create(:execution, streaming: true, metadata: {}) + create(:execution, streaming: false, metadata: {time_to_first_token_ms: 900}) + + expect(execution_class.avg_time_to_first_token).to eq(200) + end + + # Regression: this used to pluck every streaming execution's metadata + # blob into Ruby to average one key. + it "aggregates in SQL rather than loading metadata rows" do + create(:execution, streaming: true, metadata: {time_to_first_token_ms: 100}) + + queries = capture_sql { execution_class.avg_time_to_first_token } + + expect(queries.size).to eq(1) + expect(queries.first).to include("AVG(") + expect(queries.first).not_to match(/SELECT "ruby_llm_agents_executions"\."metadata"/) + end end describe ".trend_analysis" do diff --git a/spec/support/sql_capture.rb b/spec/support/sql_capture.rb new file mode 100644 index 00000000..c1c8adf9 --- /dev/null +++ b/spec/support/sql_capture.rb @@ -0,0 +1,23 @@ +# frozen_string_literal: true + +# Collects the SQL statements executed inside a block. +# +# Used by the dashboard performance regressions to assert on query count and +# shape (no duplicate aggregates, no SELECT * of the detail table, and so on). +# Schema and transaction statements are excluded. +module SqlCapture + def capture_sql + statements = [] + subscriber = ActiveSupport::Notifications.subscribe("sql.active_record") do |*, payload| + statements << payload[:sql] unless /SCHEMA|TRANSACTION/.match?(payload[:name].to_s) + end + yield + statements + ensure + ActiveSupport::Notifications.unsubscribe(subscriber) + end +end + +RSpec.configure do |config| + config.include SqlCapture +end