diff --git a/CHANGELOG.md b/CHANGELOG.md index 50e736f6e..e98a3518d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,33 @@ All notable changes to this project will be documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). +## [Unreleased] + +Upgrading the dashboard: run `bin/rails generate action_agent:install --skip` +and `bin/rails db:migrate` to install migration 033, +`add_agent_run_execution_leases`. Until it runs, agent runs take no leases +and a run whose worker dies stays running as before. + +### Fixed + +- **A run whose worker died is failed as lost instead of running forever** + (`actionagent`). Since a run is claimed once, a worker that died after + its claim left the run `running` for good: a redelivered job leaves a + running run alone. Each claim (the execution job's, the resume job's, + `Agent#test_execute`'s) now takes a lease (migration 033, + `config.run_lease_duration`, 30 minutes by default) that each LLM or + tool call renews. A running run whose lease ran out is failed with + `error_class` `ActionAgent::AgentRun::WorkerLost` when its page or the + run list is read, or when `ActionAgent::AgentRunExpiryJob` runs (not + scheduled by default). Nothing is executed again: the run's provider and + tool calls may already have taken effect. A worker that was only slow + has its result discarded, as a cancelled run's is, and a result now + only lands while the run holds its worker's lease, so whatever ended + the run first is kept. `test_execute` records its result the same way, + so a cancel during a synchronous test run is no longer overwritten. A + run with no lease, such as one running when the migration is installed, + is never failed as lost. + ## [1.9.8] - 2026-11-12 The dashboard holds a run to its catalog's pass bars: a product's and a diff --git a/actionagent/app/controllers/action_agent/api/agent_runs_controller.rb b/actionagent/app/controllers/action_agent/api/agent_runs_controller.rb index e8c376000..3607f6b41 100644 --- a/actionagent/app/controllers/action_agent/api/agent_runs_controller.rb +++ b/actionagent/app/controllers/action_agent/api/agent_runs_controller.rb @@ -8,6 +8,7 @@ class AgentRunsController < BaseController # GET /api/runs/:id def show @run.expire_overdue_input_requests! + @run.expire_if_lost! render json: { run: run_json(@run), messages: interaction_messages(@run), @@ -29,6 +30,8 @@ def cancel def index # Scoped to the caller's own agents: this listed (and counted) every # run in the database regardless of who owned it. + # A run whose worker was lost is listed as failed, not as running. + AgentRun.expire_lost!(AgentRun.where(agent: owner_agents)) scope = AgentRun.includes(:agent, :pending_input_requests).with_attachments.where(agent: owner_agents).recent scope = scope.where(agent_id: params[:agent_id]) if params[:agent_id].present? diff --git a/actionagent/app/jobs/action_agent/agent_execution_job.rb b/actionagent/app/jobs/action_agent/agent_execution_job.rb index cef7c08b2..83b9ac1eb 100644 --- a/actionagent/app/jobs/action_agent/agent_execution_job.rb +++ b/actionagent/app/jobs/action_agent/agent_execution_job.rb @@ -12,6 +12,9 @@ def perform(run_id) # retry of a failed run would re-run the generation. return unless claim_pending(run) + # This worker's lease: only while the run is still running under it is + # the result recorded. + token = run.execution_token run.add_log("Starting execution", level: :info) begin @@ -20,12 +23,12 @@ def perform(run_id) # Build the agent class dynamically based on configuration result = execute_agent(agent_record, run) - run.unless_cancelled do + run.unless_cancelled(token: token) do run.record_result!(result, segment_started_at: run.started_at) run.add_log(result[:input_requests].present? ? "Execution paused for input" : "Execution completed successfully", level: :info) end rescue => e - run.unless_cancelled do + run.unless_cancelled(token: token) do run.record_failure!(e) run.add_log("Execution failed: #{e.message}", level: :error) end @@ -46,11 +49,12 @@ def perform(run_id) # with Rails 7.2, whose deferred transactions cannot write once another # writer has committed. Nothing is held over the generation, so a cancel # never waits for it. The update skips callbacks, so the status change is - # broadcast here. + # broadcast here. The claim takes the run's lease (AgentRun.lease_attributes), + # so the reloaded run carries this worker's token. def claim_pending(run) now = Time.current claimed = AgentRun.where(id: run.id, status: AgentRun.statuses[:pending]) - .update_all(status: AgentRun.statuses[:running], started_at: now, updated_at: now) + .update_all(status: AgentRun.statuses[:running], started_at: now, updated_at: now, **AgentRun.lease_attributes(now)) return false if claimed.zero? run.reload diff --git a/actionagent/app/jobs/action_agent/agent_resume_job.rb b/actionagent/app/jobs/action_agent/agent_resume_job.rb index 2bfd8c1cb..cbc98cbe4 100644 --- a/actionagent/app/jobs/action_agent/agent_resume_job.rb +++ b/actionagent/app/jobs/action_agent/agent_resume_job.rb @@ -24,6 +24,8 @@ def perform(input_request_id) pause = claim_pause(run, request) return unless pause + token = run.execution_token + segment_started_at = Time.current secrets = pause.select { |paused| paused.kind == "secret" }.filter_map(&:answer) @@ -39,13 +41,13 @@ def perform(input_request_id) } ) - run.unless_cancelled do + run.unless_cancelled(token: token) do run.record_result!(result, segment_started_at: segment_started_at) run.add_log(result[:input_requests].present? ? "Execution paused for input" : "Execution completed successfully", level: :info) end rescue => e message = ActiveAgent::InputRequest.scrub(e.message, secrets) - run.unless_cancelled do + run.unless_cancelled(token: token) do run.record_failure!(e, message: message) run.add_log("Execution failed: #{message}", level: :error) end @@ -60,7 +62,8 @@ def perform(input_request_id) # Moves the run from awaiting_input to running when every request of the # pause is settled, under the run's row lock, and returns the pause's # requests in call order; nil when this job is not the one to resume it, - # or when the request's pause is not the one the run waits on. + # or when the request's pause is not the one the run waits on. The resumed + # segment takes a lease of its own, under a new token. def claim_pause(run, request) run.with_lock do next nil unless run.awaiting_input? && request.current_pause? @@ -68,7 +71,7 @@ def claim_pause(run, request) pause = request.pause_requests.order(:id).to_a next nil unless pause.all? { |paused| paused.answered? || paused.declined? } - run.update!(status: :running) + run.update!(status: :running, **AgentRun.lease_attributes) pause end end diff --git a/actionagent/app/jobs/action_agent/agent_run_expiry_job.rb b/actionagent/app/jobs/action_agent/agent_run_expiry_job.rb new file mode 100644 index 000000000..339aa9457 --- /dev/null +++ b/actionagent/app/jobs/action_agent/agent_run_expiry_job.rb @@ -0,0 +1,23 @@ +# frozen_string_literal: true + +module ActionAgent + # Fails the runs whose lease ran out (AgentRun.expire_lost!): running, with + # no claim, renewal or result from their worker within + # ActionAgent.run_lease_duration. A run's own page and the run list fail + # the lost runs they reach; this job reaches the rest. It never executes a + # run again. + # + # Not scheduled by default. To schedule it: + # + # # config/recurring.yml + # agent_run_expiry: + # class: ActionAgent::AgentRunExpiryJob + # schedule: every 5 minutes + class AgentRunExpiryJob < ApplicationJob + queue_as :default + + def perform + AgentRun.expire_lost! + end + end +end diff --git a/actionagent/app/models/action_agent/agent.rb b/actionagent/app/models/action_agent/agent.rb index 870e8cac9..ca33c166e 100644 --- a/actionagent/app/models/action_agent/agent.rb +++ b/actionagent/app/models/action_agent/agent.rb @@ -492,22 +492,26 @@ def execute(input_prompt, action: nil, attachments: [], actor: nil, runtime_sand # Quick test execution (synchronous). A run that pauses for input comes # back `awaiting_input` with its requests stored, and AgentResumeJob - # finishes it once they are answered. + # finishes it once they are answered. The run is created running, under + # a lease, as a job's claim would leave it, and its result is recorded + # as a job's is: not over a cancel, nor once the run left its lease. def test_execute(input_prompt, action: nil, attachments: [], actor: nil, runtime_sandbox: nil, **params) ensure_executable! run = create_run( input_prompt, action: action, attachments: attachments, params: params, - actor: actor, runtime_sandbox: runtime_sandbox, status: :running, started_at: Time.current + actor: actor, runtime_sandbox: runtime_sandbox, status: :running, started_at: Time.current, + **AgentRun.lease_attributes ) run.actor = actor + token = run.execution_token begin # Build and execute the agent result = AgentExecutionService.call(self, run) - run.record_result!(result, segment_started_at: run.started_at) + run.unless_cancelled(token: token) { run.record_result!(result, segment_started_at: run.started_at) } rescue => e - run.record_failure!(e) + run.unless_cancelled(token: token) { run.record_failure!(e) } end run diff --git a/actionagent/app/models/action_agent/agent_run.rb b/actionagent/app/models/action_agent/agent_run.rb index 51250d838..70b78c35a 100644 --- a/actionagent/app/models/action_agent/agent_run.rb +++ b/actionagent/app/models/action_agent/agent_run.rb @@ -19,6 +19,11 @@ def initialize(message = "Attachments need Active Storage in the host app (run ` end end + # The error class recorded on a run failed as lost: running past its + # lease with no news from its worker (see #expire_if_lost!). Never + # raised; it names the failure, as record_failure! names any other. + class WorkerLost < StandardError; end + # Files uploaded with the run. The execution service delivers them to # the model (images and PDFs as data URIs, text inlined) and the # persisted user message keeps a manifest of them. @@ -165,6 +170,37 @@ def self.input_param_sql(key) end end + # Whether migration 033's lease columns are installed. A host that + # upgraded the gem without running the generator takes no leases and + # runs as before, instead of failing every claim on a missing column. + def self.execution_leases? + (%w[execution_token execution_expires_at] - column_names).empty? + end + + # The attributes a claim writes to take a run for one execution segment: + # a token of its own, and an expiry ActionAgent.run_lease_duration from + # +now+. Empty when leases are off (no columns, or no duration). + # @return [Hash] + def self.lease_attributes(now = Time.current) + duration = ActionAgent.run_lease_duration + return {} unless duration && execution_leases? + + { execution_token: SecureRandom.uuid, execution_expires_at: now + duration } + end + + # Pushes the lease's expiry out by ActionAgent.run_lease_duration, while + # the run is still running under this copy's token. A run that finished, + # paused, or was taken under another token is left alone. Returns + # whether the lease was renewed. + # @return [Boolean] + def renew_lease!(now = Time.current) + duration = ActionAgent.run_lease_duration + return false unless duration && self.class.execution_leases? && execution_token + + self.class.where(id: id, status: self.class.statuses[:running], execution_token: execution_token) + .update_all(execution_expires_at: now + duration) == 1 + end + # Callbacks before_validation :set_trace_id, on: :create after_update_commit :broadcast_update, if: :saved_change_to_status? @@ -185,6 +221,7 @@ def add_log(message, level: :info) # a "started" event is pending until a "done"/"error" with the same eid # lands. update_column: no validations/callbacks, safe from the run's own # execution thread; reads current DB state so add_log interleaves safely. + # An event is the run's sign of progress, so it renews the run's lease. def append_event(eid:, kind:, label:, status: "done", detail: nil, duration_ms: nil) event = { "at" => Time.current.iso8601(3), @@ -197,6 +234,7 @@ def append_event(eid:, kind:, label:, status: "done", detail: nil, duration_ms: event["duration_ms"] = duration_ms if duration_ms current = self.class.where(id: id).pick(:logs) || [] update_column(:logs, current + [ event ]) + renew_lease! event end @@ -346,6 +384,54 @@ def cancel!(reason = "Cancelled by user") cancelled end + # Running runs whose lease ran out: no claim, renewal or result from + # their worker within ActionAgent.run_lease_duration. A run without a + # lease (claimed before migration 033, or with leases off) is never + # among them. Needs the lease columns (see .execution_leases?). + scope :lost, ->(now = Time.current) { + running.where.not(execution_token: nil).where(execution_expires_at: ..now) + } + + # Fails every lost run in +relation+ (see #expire_if_lost!) and returns + # how many it failed. Nothing without the lease columns. + # @return [Integer] + def self.expire_lost!(relation = all, now: Time.current) + return 0 unless execution_leases? + + relation.lost(now).find_each.count { |run| run.expire_if_lost!(now) } + end + + # Fails the run as lost when it is still running under the lease this + # copy read and that lease has run out, in one conditional update, so a + # renewal, a result or a cancel that lands first wins and this changes + # nothing. The run is not executed again: its worker may have died, or + # may only be slow, and whatever its provider and tool calls did may + # already have happened; a slow worker's result is then discarded (see + # #unless_cancelled). Returns whether this call failed the run, which is + # reloaded either way it touches the database. + # @return [Boolean] + def expire_if_lost!(now = Time.current) + return false unless self.class.execution_leases? && running? && execution_token && + execution_expires_at && execution_expires_at <= now + + message = "The run's worker stopped reporting progress (its lease expired at #{execution_expires_at.iso8601}). " \ + "The run was not executed again; its provider and tool calls may already have taken effect." + changed = self.class + .where(id: id, status: self.class.statuses[:running], execution_token: execution_token) + .where(execution_expires_at: ..now) + .update_all( + status: self.class.statuses[:failed], completed_at: now, error_message: message, + output_metadata: output_metadata.to_h.merge("error_class" => WorkerLost.name), + execution_token: nil, execution_expires_at: nil, updated_at: now + ) + reload + return false if changed.zero? + + add_log(message, level: :error) + broadcast_update + true + end + # Expires the run's overdue requests for input, which fails the run (see # InputRequest#expire!). Returns the run, reloaded when a request # expired. @@ -376,9 +462,9 @@ def record_result!(result, segment_started_at:) transaction do if result[:input_requests].present? InputRequest.record_pause!(self, result[:input_requests], checkpoint: result[:checkpoint]) - update!(attributes.merge(status: :awaiting_input)) + update!(attributes.merge(status: :awaiting_input, **lease_release_attributes)) else - update!(attributes.merge(output: result[:output], status: :complete, completed_at: Time.current)) + update!(attributes.merge(output: result[:output], status: :complete, completed_at: Time.current, **lease_release_attributes)) end end end @@ -395,19 +481,31 @@ def record_failure!(error, message: error.message) completed_at: Time.current, error_message: message, error_backtrace: error.backtrace&.first(10)&.join("\n"), - output_metadata: output_metadata.to_h.merge("error_class" => error.class.name) + output_metadata: output_metadata.to_h.merge("error_class" => error.class.name), + **lease_release_attributes ) end # Yields under the run's row lock unless the run was cancelled meanwhile, # so a cancel that arrived while the run executed is never overwritten by - # the result. Returns whether it yielded. - def unless_cancelled + # the result. Given the +token+ of the worker's lease, it also yields only + # while the run still holds that token. Every write that ends a segment + # releases the lease, so a worker whose run was ended under it (failed as + # lost, say) or taken for another segment has its result discarded. + # Returns whether it yielded. + # + # @param token [String, nil] the lease token the worker's claim took; nil + # (no lease) checks for a cancel only + def unless_cancelled(token: nil) with_lock do if cancelled? add_log("Execution finished after cancellation; result discarded", level: :info) next false end + if token && execution_token != token + add_log("Execution finished after its run was ended or taken by another worker; result discarded", level: :warn) + next false + end yield true @@ -416,6 +514,12 @@ def unless_cancelled private + # Ending a segment ends its lease: nothing renews it, and no worker holds + # the run until the next claim. + def lease_release_attributes + self.class.execution_leases? ? { execution_token: nil, execution_expires_at: nil } : {} + end + def add_tokens(recorded, segment) return recorded if segment.nil? diff --git a/actionagent/lib/action_agent.rb b/actionagent/lib/action_agent.rb index c17266dba..a73f6ab22 100644 --- a/actionagent/lib/action_agent.rb +++ b/actionagent/lib/action_agent.rb @@ -829,6 +829,18 @@ def claude_code_auth=(value) # @return [ActiveSupport::Duration, nil] attr_accessor :input_request_ttl + # How long a claimed run stays its worker's without news from it. Each + # claim (the execution job's, the resume job's, a synchronous test run's) + # takes a lease this long under a token of its own, and each LLM or tool + # call the run makes renews it. A run whose lease ran out is failed as + # lost once its page, the run list or AgentRunExpiryJob reaches it, and a + # worker that finishes after that has its result discarded. Nothing is + # executed again. 30 minutes by default: one provider call longer than + # this, with no progress in between, is taken for a lost worker. nil + # takes no leases, as before migration 033. + # @return [ActiveSupport::Duration, nil] + attr_accessor :run_lease_duration + # Whether API keys and provider credentials are encrypted at rest with # Active Record Encryption. On by default, which requires the host app # to have run `rails db:encryption:init`. Turning it off stores those @@ -1356,6 +1368,7 @@ def reset! @agent_polymorphic_name = nil @encrypt_credentials = true @input_request_ttl = 1.day + @run_lease_duration = 30.minutes @github_client_id = nil @github_client_secret = nil @github_oauth_scopes = "repo read:user" diff --git a/actionagent/lib/generators/action_agent/templates/action_agent.rb.erb b/actionagent/lib/generators/action_agent/templates/action_agent.rb.erb index b5a7d72a9..77c2d9e46 100644 --- a/actionagent/lib/generators/action_agent/templates/action_agent.rb.erb +++ b/actionagent/lib/generators/action_agent/templates/action_agent.rb.erb @@ -169,6 +169,17 @@ ActionAgent.configure do |config| # # config.input_request_ttl = 1.day + # ========================================================================== + # Agent runs + # ========================================================================== + # + # How long a running run stays its worker's without progress (an LLM or + # tool call) before it is failed as lost. Its result is then discarded if + # the worker was only slow; nothing is run again. Schedule + # ActionAgent::AgentRunExpiryJob to fail the lost runs nobody looks at. + # + # config.run_lease_duration = 30.minutes + # ========================================================================== # Host integration # ========================================================================== diff --git a/actionagent/lib/generators/action_agent/templates/migrations/033_add_agent_run_execution_leases.rb.erb b/actionagent/lib/generators/action_agent/templates/migrations/033_add_agent_run_execution_leases.rb.erb new file mode 100644 index 000000000..af5717b3d --- /dev/null +++ b/actionagent/lib/generators/action_agent/templates/migrations/033_add_agent_run_execution_leases.rb.erb @@ -0,0 +1,10 @@ +# frozen_string_literal: true + +class AddAgentRunExecutionLeases < ActiveRecord::Migration<%= migration_version %> + def change + add_column "#{ActionAgent.table_name_prefix}agent_runs", :execution_token, :string + add_column "#{ActionAgent.table_name_prefix}agent_runs", :execution_expires_at, :datetime + add_index "#{ActionAgent.table_name_prefix}agent_runs", [ :status, :execution_expires_at ], + name: "index_#{ActionAgent.table_name_prefix}agent_runs_on_status_and_lease" + end +end diff --git a/actionagent/test/install_generator_test.rb b/actionagent/test/install_generator_test.rb index 9583c43ad..3c894051d 100644 --- a/actionagent/test/install_generator_test.rb +++ b/actionagent/test/install_generator_test.rb @@ -293,6 +293,29 @@ class ActionAgentInstallGeneratorTest < Rails::Generators::TestCase connection&.drop_table(table, if_exists: true) if table end + test "run lease columns and their index install under a custom prefix and reverse" do + run_generator [ "--skip-routes" ] + connection = ActiveRecord::Base.connection + prefix = "lease_probe_" + table = "#{prefix}agent_runs" + connection.create_table(table, force: true) { |t| t.integer :status } + ActionAgent.table_name_prefix = prefix + namespace = Module.new + namespace.module_eval(File.read(migration_file_name("db/migrate/add_agent_run_execution_leases.rb"))) + migration = namespace::AddAgentRunExecutionLeases.new + + ActiveRecord::Migration.suppress_messages { migration.migrate(:up) } + assert connection.column_exists?(table, :execution_token, :string) + assert connection.column_exists?(table, :execution_expires_at, :datetime) + assert connection.index_exists?(table, [ :status, :execution_expires_at ], name: "index_#{prefix}agent_runs_on_status_and_lease") + ActiveRecord::Migration.suppress_messages { migration.migrate(:down) } + assert_not connection.column_exists?(table, :execution_token) + assert_not connection.column_exists?(table, :execution_expires_at) + ensure + ActionAgent.table_name_prefix = "active_agent_" + connection&.drop_table(table, if_exists: true) if table + end + test "files in the numbered template directory that break the naming convention are not emitted" do with_numbered_templates( "001_create_widgets.rb.erb" => numbered_template("CreateWidgets"), diff --git a/actionagent/test/run_lease_test.rb b/actionagent/test/run_lease_test.rb new file mode 100644 index 000000000..46231054e --- /dev/null +++ b/actionagent/test/run_lease_test.rb @@ -0,0 +1,541 @@ +# frozen_string_literal: true + +require "test_helper" + +# Every claim of a run for an execution segment takes a lease: a token of +# its own and an expiry, renewed by each LLM or tool call the run makes. +class RunLeaseTest < ActiveSupport::TestCase + def setup + @agent = ActionAgent::Agent.create!(name: "Support", provider: "openai", model: "gpt-4o-mini") + @run = @agent.agent_runs.create!(input_prompt: "hi", status: :pending) + end + + def answer + { output: "answer", metadata: {}, usage: {} } + end + + # Records the run's lease as the generation sees it, from the database. + def lease_seen(into) + lambda do |_agent, run, **| + into << ActionAgent::AgentRun.where(id: run.id).pick(:execution_token, :execution_expires_at) + answer + end + end + + def paused_run(token: "segment-1") + @run.update!(status: :awaiting_input, started_at: 1.minute.ago, execution_token: token) + ActionAgent::InputRequest.create!( + subject: @run, kind: "text", prompt: "Where to?", tool_call_id: "call_1", pause_key: "pause_1", + status: :answered, answer: "Lisbon", checkpoint: "{}" + ) + end + + test "the execution job's claim takes a lease for the run" do + seen = [] + freeze_time do + ActionAgent::AgentExecutionService.stub(:call, lease_seen(seen)) do + ActionAgent::AgentExecutionJob.perform_now(@run.id) + end + + token, expires_at = seen.sole + assert_match(/\A\h{8}-\h{4}-\h{4}-\h{4}-\h{12}\z/, token) + assert_equal 30.minutes.from_now, expires_at + end + end + + test "a resumed segment takes a lease under a new token" do + request = paused_run(token: "segment-1") + seen = [] + ActionAgent::AgentExecutionService.stub(:call, lease_seen(seen)) do + ActionAgent::AgentResumeJob.perform_now(request.id) + end + + token, expires_at = seen.sole + assert token.present? + assert_not_equal "segment-1", token + assert_in_delta 30.minutes.from_now, expires_at, 5.seconds + end + + test "a synchronous test run is created under a lease" do + seen = [] + ActionAgent::AgentExecutionService.stub(:call, lease_seen(seen)) do + @agent.test_execute("hi") + end + + token, expires_at = seen.sole + assert token.present? + assert_in_delta 30.minutes.from_now, expires_at, 5.seconds + end + + test "two claims never share a token" do + other = @agent.agent_runs.create!(input_prompt: "hi", status: :pending) + seen = [] + ActionAgent::AgentExecutionService.stub(:call, lease_seen(seen)) do + [ @run, other ].each { |run| ActionAgent::AgentExecutionJob.perform_now(run.id) } + end + + assert_equal 2, seen.map(&:first).uniq.size + end + + test "a progress event renews the lease of the run it belongs to" do + @run.update!(status: :running, execution_token: "mine", execution_expires_at: 1.minute.from_now) + + freeze_time do + @run.append_event(eid: "e1", kind: :llm, label: "gpt-4o-mini", status: "started") + + assert_equal 30.minutes.from_now, @run.reload.execution_expires_at + end + end + + test "a renewal leaves a run that is not running under the copy's token alone" do + copy = ActionAgent::AgentRun.find(@run.id) + copy.execution_token = "mine" + expires_at = 1.minute.from_now.change(usec: 0) + + { "theirs" => :running, "mine" => :complete }.each do |token, status| + @run.update!(status: status, execution_token: token, execution_expires_at: expires_at) + + assert_equal false, copy.renew_lease! + assert_equal expires_at, @run.reload.execution_expires_at + end + end + + test "no lease is taken without a lease duration" do + seen = [] + with_lease_duration(nil) do + ActionAgent::AgentExecutionService.stub(:call, lease_seen(seen)) do + ActionAgent::AgentExecutionJob.perform_now(@run.id) + end + end + + assert_equal [ [ nil, nil ] ], seen + assert @run.reload.complete? + end + + test "no lease is taken before migration 033 has run" do + seen = [] + ActionAgent::AgentRun.stub(:execution_leases?, false) do + ActionAgent::AgentExecutionService.stub(:call, lease_seen(seen)) do + ActionAgent::AgentExecutionJob.perform_now(@run.id) + end + @run.update_columns(status: ActionAgent::AgentRun.statuses[:running], execution_token: "mine") + + assert_equal false, @run.renew_lease! + end + + assert_equal [ [ nil, nil ] ], seen + end + + def with_lease_duration(duration) + previous = ActionAgent.run_lease_duration + ActionAgent.run_lease_duration = duration + yield + ensure + ActionAgent.run_lease_duration = previous + end +end + +# A worker records its segment's result only while the run is still running +# under the token its claim took. Whatever ended the run under it, or took +# it for another segment, wins over the late result. +class RunLeaseFenceTest < ActiveSupport::TestCase + WorkerLost = Class.new(StandardError) { def self.name = "WorkerLost" } + + def setup + @agent = ActionAgent::Agent.create!(name: "Support", provider: "openai", model: "gpt-4o-mini") + @run = @agent.agent_runs.create!(input_prompt: "hi", status: :pending) + end + + # A generation during which something else fails the run, as a sweeper + # that took the worker for lost would. Returns +outcome+'s result. + def failed_under_it(outcome = -> { { output: "late answer", metadata: {}, usage: {} } }) + lambda do |_agent, run, **| + ActionAgent::AgentRun.find(run.id).record_failure!(WorkerLost.new("lease expired")) + outcome.call + end + end + + def discarded?(run) + Array(run.logs).any? { |log| log["message"].to_s.include?("ended or taken by another worker; result discarded") } + end + + test "a worker whose run was ended under it does not record its result" do + ActionAgent::AgentExecutionService.stub(:call, failed_under_it) do + ActionAgent::AgentExecutionJob.perform_now(@run.id) + end + + @run.reload + assert @run.failed?, "the late result turned the run #{@run.status}" + assert_nil @run.output + assert_equal "lease expired", @run.error_message + assert_equal "WorkerLost", @run.output_metadata["error_class"] + assert discarded?(@run) + end + + test "a worker whose run was ended under it does not record its own failure" do + exploding = failed_under_it(-> { raise "provider down" }) + ActionAgent::AgentExecutionService.stub(:call, exploding) do + assert_raises(RuntimeError) { ActionAgent::AgentExecutionJob.perform_now(@run.id) } + end + + assert_equal "lease expired", @run.reload.error_message + assert discarded?(@run) + end + + test "a resumed segment whose run was ended under it does not record its result" do + @run.update!(status: :awaiting_input, started_at: 1.minute.ago) + request = ActionAgent::InputRequest.create!( + subject: @run, kind: "text", prompt: "Where to?", tool_call_id: "call_1", pause_key: "pause_1", + status: :answered, answer: "Lisbon", checkpoint: "{}" + ) + + ActionAgent::AgentExecutionService.stub(:call, failed_under_it) do + ActionAgent::AgentResumeJob.perform_now(request.id) + end + + @run.reload + assert @run.failed? + assert_nil @run.output + end + + test "a synchronous test run that was ended under it does not record its result" do + run = nil + ActionAgent::AgentExecutionService.stub(:call, failed_under_it) do + run = @agent.test_execute("hi") + end + + assert run.reload.failed? + assert_nil run.output + assert_equal "lease expired", run.error_message + end + + test "a synchronous test run that was ended under it does not record its own failure" do + run = nil + ActionAgent::AgentExecutionService.stub(:call, failed_under_it(-> { raise "provider down" })) do + run = @agent.test_execute("hi") + end + + assert run.reload.failed? + assert_equal "lease expired", run.error_message + end + + test "a synchronous test run cancelled while it ran stays cancelled, as a job's run does" do + cancelling = lambda do |_agent, run, **| + ActionAgent::AgentRun.find(run.id).cancel! + { output: "finished anyway", metadata: {}, usage: {} } + end + run = nil + ActionAgent::AgentExecutionService.stub(:call, cancelling) do + run = @agent.test_execute("hi") + end + + assert run.reload.cancelled? + assert_nil run.output + end + + test "a worker whose run was taken under another token does not record its result" do + retaken = lambda do |_agent, run, **| + ActionAgent::AgentRun.where(id: run.id).update_all(execution_token: "another-segment") + { output: "late answer", metadata: {}, usage: {} } + end + ActionAgent::AgentExecutionService.stub(:call, retaken) do + ActionAgent::AgentExecutionJob.perform_now(@run.id) + end + + @run.reload + assert @run.running? + assert_equal "another-segment", @run.execution_token + assert_nil @run.output + end + + test "a segment that ends releases its lease, whether it completed, paused or failed" do + outcomes = { + complete: { output: "answer", metadata: {}, usage: {} }, + awaiting_input: { output: nil, metadata: {}, usage: {}, checkpoint: { "messages" => [] }, + input_requests: [ ActiveAgent::InputRequest.text("Where to?").with(tool_call_id: "call_1", tool_name: "ask_user") ] }, + failed: -> { raise "provider down" } + } + outcomes.each do |status, outcome| + run = @agent.agent_runs.create!(input_prompt: "hi", status: :pending) + held = nil + service = lambda do |_agent, executing, **| + held = ActionAgent::AgentRun.where(id: executing.id).pick(:execution_token) + outcome.respond_to?(:call) ? outcome.call : outcome + end + ActionAgent::AgentExecutionService.stub(:call, service) do + ActionAgent::AgentExecutionJob.perform_now(run.id) + rescue RuntimeError + nil + end + + run.reload + assert held.present?, "the #{status} segment ran without a lease" + assert_equal status.to_s, run.status + assert_nil run.execution_token, "a #{status} run kept its lease token" + assert_nil run.execution_expires_at + end + end +end + +# The worker is slow, not dead: it is still in its generation, on its own +# connection, when the run is failed as lost on another. Not transactional, +# so each sees what the other committed; the agent and its runs are removed. +class RunLeaseLateWorkerTest < ActiveSupport::TestCase + self.use_transactional_tests = false + + def setup + @agent = ActionAgent::Agent.create!(name: "Support", provider: "openai", model: "gpt-4o-mini") + @run = @agent.agent_runs.create!(input_prompt: "hi", status: :pending) + end + + def teardown + ActionAgent::Agent.find_by(id: @agent&.id)&.destroy! + end + + test "a late worker's result does not overwrite a run failed as lost meanwhile" do + started = Concurrent::Event.new + release = Concurrent::Event.new + held = lambda do |_agent, _run, **| + started.set + release.wait(10) + { output: "late answer", metadata: {}, usage: {} } + end + worker = Thread.new do + ActiveRecord::Base.connection_pool.with_connection do + ActionAgent::AgentExecutionService.stub(:call, held) do + ActionAgent::AgentExecutionJob.perform_now(@run.id) + end + end + end + assert started.wait(10), "the worker never started its generation" + + lost = Class.new(StandardError) { def self.name = "WorkerLost" } + ActionAgent::AgentRun.find(@run.id).record_failure!(lost.new("lease expired")) + release.set + worker.join + + @run.reload + assert @run.failed?, "the late worker turned the run #{@run.status}" + assert_nil @run.output + assert_equal "lease expired", @run.error_message + end +end + +# A running run whose lease ran out is failed as lost, once, and never +# executed again. Its page, the run list and AgentRunExpiryJob find it. +class RunLeaseExpiryTest < ActionDispatch::IntegrationTest + def setup + @agent = ActionAgent::Agent.create!(name: "Support", provider: "openai", model: "gpt-4o-mini") + end + + def leased_run(status: :running, expires_at: 1.minute.ago, token: "lost-worker", **attributes) + @agent.agent_runs.create!( + input_prompt: "hi", status: status, started_at: 1.hour.ago, + execution_token: token, execution_expires_at: expires_at, **attributes + ) + end + + def announcements(run) + seen = [] + recording = ->(stream, payload) { seen << payload[:status] if stream == "agent_run_#{run.id}" } + ActionAgent::LiveUpdates.stub(:broadcast, recording) { yield } + seen + end + + test "a running run past its lease is failed as lost, once, and announced once" do + run = leased_run(output_metadata: { "provider" => "openai" }) + + announced = announcements(run) do + assert_equal true, run.expire_if_lost! + assert_equal false, run.expire_if_lost! + end + + run.reload + assert run.failed? + assert_equal({ "provider" => "openai", "error_class" => "ActionAgent::AgentRun::WorkerLost" }, run.output_metadata) + assert_match(/stopped reporting progress.*not executed again/, run.error_message) + assert_not_nil run.completed_at + assert_nil run.execution_token + assert_nil run.execution_expires_at + assert_equal %w[failed], announced + assert_equal 1, Array(run.logs).count { |log| log["message"].to_s.include?("stopped reporting progress") } + end + + test "a lost run is not executed again" do + run = leased_run + calls = 0 + ActionAgent::AgentExecutionService.stub(:call, ->(*) { calls += 1 }) do + assert_no_enqueued_jobs { ActionAgent::AgentRunExpiryJob.perform_now } + ActionAgent::AgentExecutionJob.perform_now(run.id) + end + + assert_equal 0, calls + assert run.reload.failed? + end + + test "a run within its lease, or renewed since it was read, is left running" do + live = leased_run(expires_at: 1.minute.from_now) + renewed = leased_run + stale = ActionAgent::AgentRun.find(renewed.id) + renewed.renew_lease! + + # The run's page checks on every read: a run within its lease costs no query. + assert_no_queries { assert_equal false, live.expire_if_lost! } + assert_equal false, stale.expire_if_lost! + assert live.reload.running? + assert renewed.reload.running? + end + + test "a run taken for a new segment since it was read is left to that segment" do + run = leased_run + stale = ActionAgent::AgentRun.find(run.id) + run.update!(execution_token: "next-segment") + + assert_equal false, stale.expire_if_lost! + assert run.reload.running? + assert stale.running?, "the copy was not reloaded" + end + + test "only running runs are expired, whatever their lease columns say" do + others = %i[pending complete failed cancelled awaiting_input].map { |status| leased_run(status: status) } + before = others.map { |run| run.reload.attributes } + + assert_equal 0, ActionAgent::AgentRun.expire_lost! + + assert_equal before, others.map { |run| run.reload.attributes } + end + + test "a run without a lease, such as one started before migration 033, is never expired" do + run = leased_run(token: nil, expires_at: nil) + + assert_empty ActionAgent::AgentRun.lost + assert_equal 0, ActionAgent::AgentRun.expire_lost! + assert_equal false, run.expire_if_lost! + assert run.reload.running? + end + + test "nothing is expired without the lease columns" do + run = leased_run + ActionAgent::AgentRun.stub(:execution_leases?, false) do + ActionAgent::AgentRun.stub(:lost, ->(*) { flunk "queried the lease columns a host has not migrated" }) do + assert_equal 0, ActionAgent::AgentRun.expire_lost! + end + assert_equal false, run.expire_if_lost! + end + + assert run.reload.running? + end + + test "a cancel that lands first wins over the expiry" do + run = leased_run + stale = ActionAgent::AgentRun.find(run.id) + run.cancel! + + assert_equal false, stale.expire_if_lost! + assert run.reload.cancelled? + end + + test "AgentRunExpiryJob fails every lost run, and only those" do + lost = [ leased_run, leased_run(token: "other-lost-worker") ] + live = leased_run(expires_at: 5.minutes.from_now) + + ActionAgent::AgentRunExpiryJob.perform_now + + assert lost.all? { |run| run.reload.failed? } + assert live.reload.running? + end + + test "a lost run's page shows it failed" do + run = leased_run + + get "/activeagents/api/runs/#{run.id}" + + assert_response :success + assert_equal "failed", JSON.parse(response.body).dig("run", "status") + end + + test "the run list shows a lost run failed" do + run = leased_run + + get "/activeagents/api/runs" + + assert_response :success + listed = JSON.parse(response.body)["runs"].find { |entry| entry["id"] == run.id } + assert_equal "failed", listed["status"] + end + + test "a worker that finishes after its run was failed as lost has its result discarded" do + run = @agent.agent_runs.create!(input_prompt: "hi", status: :pending) + outlived = lambda do |_agent, _run, **| + travel(31.minutes) { ActionAgent::AgentRunExpiryJob.perform_now } + { output: "late answer", metadata: {}, usage: {} } + end + ActionAgent::AgentExecutionService.stub(:call, outlived) do + ActionAgent::AgentExecutionJob.perform_now(run.id) + end + + run.reload + assert run.failed? + assert_nil run.output + assert_equal "ActionAgent::AgentRun::WorkerLost", run.output_metadata["error_class"] + end + + test "a healthy run whose progress renews its lease outlasts the lease duration" do + run = @agent.agent_runs.create!(input_prompt: "hi", status: :pending) + steady = lambda do |_agent, executing, **| + 3.times do |step| + travel(20.minutes) + executing.append_event(eid: "e#{step}", kind: :llm, label: "gpt-4o-mini") + ActionAgent::AgentRunExpiryJob.perform_now + end + { output: "answer", metadata: {}, usage: {} } + end + ActionAgent::AgentExecutionService.stub(:call, steady) do + ActionAgent::AgentExecutionJob.perform_now(run.id) + end + + assert run.reload.complete?, "a run that kept reporting progress was taken for lost" + assert_equal "answer", run.output + ensure + travel_back + end +end + +# Two sweeps reach the same lost run at once, each on its own connection. +class RunLeaseExpiryConcurrencyTest < ActiveSupport::TestCase + self.use_transactional_tests = false + + def setup + @agent = ActionAgent::Agent.create!(name: "Support", provider: "openai", model: "gpt-4o-mini") + end + + def teardown + ActionAgent::Agent.find_by(id: @agent&.id)&.destroy! + end + + test "two sweeps that load the same lost run fail it once" do + run = @agent.agent_runs.create!( + input_prompt: "hi", status: :running, started_at: 1.hour.ago, + execution_token: "lost-worker", execution_expires_at: 1.minute.ago + ) + barrier = Concurrent::CyclicBarrier.new(2) + announced = Concurrent::Array.new + recording = ->(stream, payload) { announced << payload[:status] if stream == "agent_run_#{run.id}" } + + results = ActionAgent::LiveUpdates.stub(:broadcast, recording) do + Array.new(2) do + Thread.new do + ActiveRecord::Base.connection_pool.with_connection do + copy = ActionAgent::AgentRun.find(run.id) + barrier.wait(10) + copy.expire_if_lost! + end + end + end.map(&:value) + end + + assert_equal [ false, true ], results.sort_by { |result| result ? 1 : 0 } + assert_equal %w[failed], announced.to_a + assert_equal 1, Array(run.reload.logs).count { |log| log["message"].to_s.include?("stopped reporting progress") } + end +end diff --git a/docs/framework/dashboard.md b/docs/framework/dashboard.md index 19250dbc0..aefdba1df 100644 --- a/docs/framework/dashboard.md +++ b/docs/framework/dashboard.md @@ -226,6 +226,43 @@ Time-series charts on the console's metrics page use the optional degrade gracefully without it; the React metrics page reads buckets the API already aggregated and needs nothing extra. +### When a run's worker is lost + +A run goes `pending`, then `running` once one worker claims it, then +`complete`, `failed`, `awaiting_input` (see [Input requests](#input-requests)) +or `cancelled`. A job delivered twice runs the run once. A worker that dies +after its claim (a kill, an out-of-memory error, a deploy that does not wait +for jobs) leaves no result, so each claim takes a lease: + +- The claim writes a token and an expiry `config.run_lease_duration` ahead + (30 minutes by default). Each LLM or tool call the run makes moves the + expiry out again. A resumed run takes a new lease under a new token. +- A running run whose lease ran out is failed as lost: `error_class` is + `ActionAgent::AgentRun::WorkerLost` and the message says so. That happens + when the run's page or the run list is read, or when + `ActionAgent::AgentRunExpiryJob` runs. The job is not scheduled by default: + +```yaml +# config/recurring.yml +agent_run_expiry: + class: ActionAgent::AgentRunExpiryJob + schedule: every 5 minutes +``` + +- A lost run is not executed again. Its provider calls may have been billed + and its tools may have acted before the worker stopped; run the prompt + again as a new run once you have checked. A worker that was only slow, + and finishes after its run was failed as lost or cancelled, has its result + discarded and a line in the run's log saying so. +- One provider call longer than the lease, with no other call in between, + looks like a lost worker. Raise `config.run_lease_duration` for agents + that wait that long; `nil` takes no leases. +- Cancelling a run does not stop a provider call already in flight; it + keeps that call's result from being recorded. +- A run already running when migration 033 was installed has no lease and + is never failed as lost. Cancel it if its worker is gone. Without the + migration, runs take no leases and behave as before. + ## Input requests A dashboard agent can stop partway through a run to ask a person something, diff --git a/test/dummy/db/migrate/033_add_agent_run_execution_leases.rb b/test/dummy/db/migrate/033_add_agent_run_execution_leases.rb new file mode 100644 index 000000000..6aa794340 --- /dev/null +++ b/test/dummy/db/migrate/033_add_agent_run_execution_leases.rb @@ -0,0 +1,10 @@ +# frozen_string_literal: true + +class AddAgentRunExecutionLeases < ActiveRecord::Migration[7.2] + def change + add_column "#{ActionAgent.table_name_prefix}agent_runs", :execution_token, :string + add_column "#{ActionAgent.table_name_prefix}agent_runs", :execution_expires_at, :datetime + add_index "#{ActionAgent.table_name_prefix}agent_runs", [ :status, :execution_expires_at ], + name: "index_#{ActionAgent.table_name_prefix}agent_runs_on_status_and_lease" + end +end diff --git a/test/dummy/db/schema.rb b/test/dummy/db/schema.rb index f18f70fea..5beb4e455 100644 --- a/test/dummy/db/schema.rb +++ b/test/dummy/db/schema.rb @@ -94,6 +94,8 @@ t.integer "duration_ms" t.text "error_backtrace" t.text "error_message" + t.datetime "execution_expires_at" + t.string "execution_token" t.json "input_params", default: {} t.text "input_prompt" t.integer "input_tokens" @@ -108,6 +110,7 @@ t.datetime "updated_at", null: false t.index [ "agent_id" ], name: "index_active_agent_agent_runs_on_agent_id" t.index [ "created_at" ], name: "index_active_agent_agent_runs_on_created_at" + t.index [ "status", "execution_expires_at" ], name: "index_active_agent_agent_runs_on_status_and_lease" t.index [ "trace_id" ], name: "index_active_agent_agent_runs_on_trace_id" end