From 0d5cd44082c500f32bfffbfda388943fb5f79d6b Mon Sep 17 00:00:00 2001 From: Katharina Przybill <30441792+kathap@users.noreply.github.com> Date: Wed, 12 Aug 2026 12:28:01 +0200 Subject: [PATCH 1/3] Fail stuck service instance 'update' operations When CCDB is briefly unavailable during a broker polling cycle, the CC polling job can fail permanently (max_attempts=1) while the broker is still processing. This leaves an update stuck: last_operation.state stays 'in progress' with no delayed job working on it, requiring operator intervention. Add ServiceOperationsUpdateInProgressCleanup, a periodic job that detects stuck 'update' operations whose polling job has permanently failed and marks the operation and its pollable job as 'failed', giving clients a definitive final state. A FOR UPDATE SKIP LOCKED guard prevents double processing across concurrent CC instances. Unlike the create cleanup, no orphan mitigation is triggered: an update targets a resource that already exists, so it must not be deprovisioned. --- ...e_operations_update_in_progress_cleanup.rb | 84 ++++++++ config/cloud_controller.yml | 3 + lib/cloud_controller/clock/scheduler.rb | 1 + .../config_schemas/clock_schema.rb | 3 + lib/cloud_controller/jobs.rb | 1 + ...rations_update_in_progress_cleanup_spec.rb | 184 ++++++++++++++++++ .../cloud_controller/clock/scheduler_spec.rb | 7 + 7 files changed, 283 insertions(+) create mode 100644 app/jobs/runtime/service_operations_update_in_progress_cleanup.rb create mode 100644 spec/unit/jobs/runtime/service_operations_update_in_progress_cleanup_spec.rb diff --git a/app/jobs/runtime/service_operations_update_in_progress_cleanup.rb b/app/jobs/runtime/service_operations_update_in_progress_cleanup.rb new file mode 100644 index 00000000000..867b8656762 --- /dev/null +++ b/app/jobs/runtime/service_operations_update_in_progress_cleanup.rb @@ -0,0 +1,84 @@ +module VCAP::CloudController + module Jobs + module Runtime + class ServiceOperationsUpdateInProgressCleanup < VCAP::CloudController::Jobs::CCJob + BATCH_SIZE = 10 + + def perform + logger.info("Cleaning up service 'update' operations stuck in 'in progress'") + cleanup_operations(ServiceInstanceOperation, ServiceInstance, :service_instance_id, 'service_instance.update') + end + + def max_attempts + 1 + end + + private + + def cleanup_operations(operation_model, instance_model, foreign_key, jobs_operation) + operation_table = operation_model.table_name + instance_table = instance_model.table_name + + stuck = operation_model. + join(instance_table, id: Sequel[operation_table][foreign_key]). + join(:jobs, resource_guid: Sequel[instance_table][:guid]). + join(:delayed_jobs, guid: Sequel[:jobs][:delayed_job_guid]). + where(Sequel[operation_table][:state] => 'in progress'). + where(Sequel[operation_table][:type] => 'update'). + where(Sequel.lit("#{operation_table}.created_at > CURRENT_TIMESTAMP - INTERVAL '?' SECOND", default_maximum_duration_seconds.to_i)). + where(Sequel[:jobs][:state] => [PollableJobModel::POLLING_STATE, PollableJobModel::FAILED_STATE]). + where(Sequel[:jobs][:operation] => jobs_operation). + exclude(Sequel[:delayed_jobs][:failed_at] => nil). + select( + Sequel[:jobs][:guid].as(:pollable_guid), + Sequel[operation_table][:id].as(:op_id), + Sequel[operation_table][foreign_key].as(:resource_id) + ). + order(Sequel[operation_table][:created_at]). + limit(BATCH_SIZE) + + stuck.each do |row| + resolve_stuck(operation_model, instance_model, row[:op_id], row[:resource_id], row[:pollable_guid]) + end + end + + def resolve_stuck(operation_model, instance_model, op_id, resource_id, pollable_guid) + operation_model.db.transaction do + operation = operation_model.where(id: op_id, state: 'in progress').for_update.skip_locked.first + return unless operation + + instance = instance_model.first(id: resource_id) + return unless instance + + instance_type = instance_model.to_s.split('::').last + + logger.info( + "#{instance_type} #{instance.guid} update operation is stuck in 'in progress'. " \ + "Setting operation's state to 'failed' and pollable job's state to 'FAILED'.", + instance_type: instance_type, + instance_guid: instance.guid, + operation_id: op_id, + pollable_job_guid: pollable_guid + ) + + operation.update(state: 'failed', + description: "Operation was stuck in 'in progress' state. Set to 'failed' by cleanup job.") + PollableJobModel.where(guid: pollable_guid).update(state: PollableJobModel::FAILED_STATE) + end + end + + def default_maximum_duration_seconds + Config.config.get(:broker_client_max_async_poll_duration_minutes).minutes + end + + def logger + @logger ||= Steno.logger('cc.background.service-operations-update-in-progress-cleanup') + end + + def job_name_in_configuration + :service_operations_update_in_progress_cleanup + end + end + end + end +end diff --git a/config/cloud_controller.yml b/config/cloud_controller.yml index 30edab7f28b..d8ea9fd2cd9 100644 --- a/config/cloud_controller.yml +++ b/config/cloud_controller.yml @@ -58,6 +58,9 @@ service_operations_initial_cleanup: service_operations_create_in_progress_cleanup: frequency_in_seconds: 3600 #1h +service_operations_update_in_progress_cleanup: + frequency_in_seconds: 3600 #1h + # One-off backfill - to be removed in a future version. lifecycle_type_backfill: frequency_in_seconds: 3600 #1h diff --git a/lib/cloud_controller/clock/scheduler.rb b/lib/cloud_controller/clock/scheduler.rb index e128e4db906..65487ab962d 100644 --- a/lib/cloud_controller/clock/scheduler.rb +++ b/lib/cloud_controller/clock/scheduler.rb @@ -26,6 +26,7 @@ class Scheduler { name: 'failed_jobs', class: Jobs::Runtime::FailedJobsCleanup }, { name: 'service_operations_initial_cleanup', class: Jobs::Runtime::ServiceOperationsInitialCleanup }, { name: 'service_operations_create_in_progress_cleanup', class: Jobs::Runtime::ServiceOperationsCreateInProgressCleanup }, + { name: 'service_operations_update_in_progress_cleanup', class: Jobs::Runtime::ServiceOperationsUpdateInProgressCleanup }, # One-off backfill - to be removed in a future version. { name: 'lifecycle_type_backfill', class: Jobs::Runtime::LifecycleTypeBackfill } ].freeze diff --git a/lib/cloud_controller/config_schemas/clock_schema.rb b/lib/cloud_controller/config_schemas/clock_schema.rb index 79b4461b66c..e5be2b4382e 100644 --- a/lib/cloud_controller/config_schemas/clock_schema.rb +++ b/lib/cloud_controller/config_schemas/clock_schema.rb @@ -37,6 +37,9 @@ class ClockSchema < VCAP::Config service_operations_create_in_progress_cleanup: { frequency_in_seconds: Integer }, + service_operations_update_in_progress_cleanup: { + frequency_in_seconds: Integer + }, # One-off backfill - to be removed in a future version. lifecycle_type_backfill: { frequency_in_seconds: Integer diff --git a/lib/cloud_controller/jobs.rb b/lib/cloud_controller/jobs.rb index eaeae0dc0d9..3abec61584b 100644 --- a/lib/cloud_controller/jobs.rb +++ b/lib/cloud_controller/jobs.rb @@ -26,6 +26,7 @@ require 'jobs/runtime/expired_orphaned_blob_cleanup' require 'jobs/runtime/expired_resource_cleanup' require 'jobs/runtime/service_operations_create_in_progress_cleanup' +require 'jobs/runtime/service_operations_update_in_progress_cleanup' require 'jobs/runtime/failed_jobs_cleanup' require 'jobs/runtime/service_operations_initial_cleanup' require 'jobs/runtime/legacy_jobs' diff --git a/spec/unit/jobs/runtime/service_operations_update_in_progress_cleanup_spec.rb b/spec/unit/jobs/runtime/service_operations_update_in_progress_cleanup_spec.rb new file mode 100644 index 00000000000..a7f7668cab8 --- /dev/null +++ b/spec/unit/jobs/runtime/service_operations_update_in_progress_cleanup_spec.rb @@ -0,0 +1,184 @@ +require 'spec_helper' + +module VCAP::CloudController + module Jobs::Runtime + RSpec.describe ServiceOperationsUpdateInProgressCleanup, job_context: :worker do + subject(:job) { ServiceOperationsUpdateInProgressCleanup.new } + + let(:fake_logger) { instance_double(Steno::Logger, info: nil, warn: nil) } + let(:max_poll_duration_minutes) { 60 } + + before do + allow(Steno).to receive(:logger).and_return(fake_logger) + TestConfig.override(broker_client_max_async_poll_duration_minutes: max_poll_duration_minutes) + end + + def prepare_stuck_service_instance( + service_instance_state: 'in progress', + service_instance_type: 'update', + service_instance_created_at: Time.now, + pollable_job_state: PollableJobModel::FAILED_STATE, + pollable_job_operation: 'service_instance.update', + delayed_job_failed_at: Time.now + ) + service_instance = create(:managed_service_instance) + + create(:service_instance_operation, + service_instance_id: service_instance.id, + type: service_instance_type, + state: service_instance_state, + created_at: service_instance_created_at) + + dj = Delayed::Job.create!( + guid: SecureRandom.uuid, + handler: 'fake', + run_at: Time.now, + failed_at: delayed_job_failed_at, + queue: 'cc-generic' + ) + + pjob = create(:pollable_job_model, + state: pollable_job_state, + operation: pollable_job_operation, + resource_guid: service_instance.guid, + resource_type: 'service_instances', + delayed_job_guid: dj.guid) + + { service_instance: service_instance, pjob: pjob, delayed_job: dj } + end + + shared_examples 'does not resolve the operation' do + it 'leaves the operation in progress and the pollable job untouched' do + scenario = subject_scenario + job.perform + expect(scenario[:service_instance].last_operation.reload.state).to eq('in progress') + expect(scenario[:pjob].reload.state).to eq(scenario[:pjob].state) + end + end + + it { is_expected.to be_a_valid_job } + + describe '#perform' do + context 'when sio state is not in progress' do + it 'does not resolve when state is succeeded' do + scenario = prepare_stuck_service_instance(service_instance_state: 'succeeded') + job.perform + expect(scenario[:service_instance].last_operation.reload.state).to eq('succeeded') + end + + it 'does not resolve when state is failed' do + scenario = prepare_stuck_service_instance(service_instance_state: 'failed') + job.perform + expect(scenario[:service_instance].last_operation.reload.state).to eq('failed') + end + end + + context 'when sio type is not update' do + let(:subject_scenario) { prepare_stuck_service_instance(service_instance_type: 'create') } + + it_behaves_like 'does not resolve the operation' + end + + context 'when sio created_at is beyond the max polling window' do + let(:subject_scenario) { prepare_stuck_service_instance(service_instance_created_at: Time.now - (max_poll_duration_minutes + 1).minutes) } + + it_behaves_like 'does not resolve the operation' + end + + context 'when delayed_job.failed_at is nil (job still running or locked)' do + let(:subject_scenario) { prepare_stuck_service_instance(delayed_job_failed_at: nil) } + + it_behaves_like 'does not resolve the operation' + end + + context 'when pollable job state is COMPLETE' do + let(:subject_scenario) { prepare_stuck_service_instance(pollable_job_state: PollableJobModel::COMPLETE_STATE) } + + it_behaves_like 'does not resolve the operation' + end + + context 'when pollable job state is PROCESSING' do + let(:subject_scenario) { prepare_stuck_service_instance(pollable_job_state: PollableJobModel::PROCESSING_STATE) } + + it_behaves_like 'does not resolve the operation' + end + + context 'when pollable job operation is not service_instance.update' do + let(:subject_scenario) { prepare_stuck_service_instance(pollable_job_operation: 'service_instance.create') } + + it_behaves_like 'does not resolve the operation' + end + + context 'when a service instance update job is stuck with state FAILED' do + it 'sets operation to failed and pollable job to FAILED' do + scenario = prepare_stuck_service_instance + job.perform + expect(scenario[:service_instance].last_operation.reload.state).to eq('failed') + expect(scenario[:pjob].reload.state).to eq(PollableJobModel::FAILED_STATE) + end + end + + context 'when a service instance update job is stuck with state POLLING (DB flip before failure hook)' do + it 'sets operation to failed and pollable job to FAILED' do + scenario = prepare_stuck_service_instance(pollable_job_state: PollableJobModel::POLLING_STATE) + job.perform + expect(scenario[:service_instance].last_operation.reload.state).to eq('failed') + expect(scenario[:pjob].reload.state).to eq(PollableJobModel::FAILED_STATE) + end + end + + context 'when there are multiple stuck jobs within the batch size' do + it 'resolves each one' do + 3.times { prepare_stuck_service_instance } + job.perform + expect(ServiceInstanceOperation.where(state: 'failed').count).to eq(3) + end + end + + context 'when there are more stuck jobs than the batch size' do + it 'processes only up to BATCH_SIZE jobs per run' do + (ServiceOperationsUpdateInProgressCleanup::BATCH_SIZE + 1).times { prepare_stuck_service_instance } + job.perform + expect(ServiceInstanceOperation.where(state: 'failed').count).to eq(ServiceOperationsUpdateInProgressCleanup::BATCH_SIZE) + end + end + end + + describe '#resolve_stuck' do + context 'when another process already resolved it (skip_locked returns nil)' do + it 'does nothing' do + scenario = prepare_stuck_service_instance + + expect do + job.send(:resolve_stuck, ServiceInstanceOperation, ServiceInstance, + -1, scenario[:service_instance].id, scenario[:pjob].guid) + end.not_to raise_error + expect(scenario[:service_instance].last_operation.reload.state).to eq('in progress') + end + end + + context 'when the operation is stuck in progress' do + it 'sets the operation state from in progress to failed' do + scenario = prepare_stuck_service_instance + op = scenario[:service_instance].last_operation + + expect do + job.send(:resolve_stuck, ServiceInstanceOperation, ServiceInstance, + op.id, scenario[:service_instance].id, scenario[:pjob].guid) + end.to change { op.reload.state }.from('in progress').to('failed') + end + + it 'sets the pollable job state to FAILED' do + scenario = prepare_stuck_service_instance(pollable_job_state: PollableJobModel::POLLING_STATE) + op = scenario[:service_instance].last_operation + + expect do + job.send(:resolve_stuck, ServiceInstanceOperation, ServiceInstance, + op.id, scenario[:service_instance].id, scenario[:pjob].guid) + end.to change { scenario[:pjob].reload.state }.from(PollableJobModel::POLLING_STATE).to(PollableJobModel::FAILED_STATE) + end + end + end + end + end +end diff --git a/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb b/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb index 21c5b94d459..8ef5921e333 100644 --- a/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb +++ b/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb @@ -22,6 +22,7 @@ module VCAP::CloudController pollable_jobs: { cutoff_age_in_days: 2 }, service_operations_initial_cleanup: { frequency_in_seconds: 600 }, service_operations_create_in_progress_cleanup: { frequency_in_seconds: 600 }, + service_operations_update_in_progress_cleanup: { frequency_in_seconds: 600 }, lifecycle_type_backfill: { frequency_in_seconds: 500 }, service_usage_events: { cutoff_age_in_days: 5 }, completed_tasks: { cutoff_age_in_days: 6 }, @@ -169,6 +170,12 @@ module VCAP::CloudController expect(block.call).to be_instance_of(Jobs::Runtime::ServiceOperationsCreateInProgressCleanup) end + expect(clock).to receive(:schedule_frequent_worker_job) do |args, &block| + expect(args).to eql(name: 'service_operations_update_in_progress_cleanup', interval: 600) + expect(Jobs::Runtime::ServiceOperationsUpdateInProgressCleanup).to receive(:new).and_call_original + expect(block.call).to be_instance_of(Jobs::Runtime::ServiceOperationsUpdateInProgressCleanup) + end + expect(clock).to receive(:schedule_frequent_worker_job) do |args, &block| expect(args).to eql(name: 'lifecycle_type_backfill', interval: 500) expect(Jobs::Runtime::LifecycleTypeBackfill).to receive(:new).and_call_original From 41eba216cee2c284baf612569ae18b37da81b7b6 Mon Sep 17 00:00:00 2001 From: Katharina Przybill <30441792+kathap@users.noreply.github.com> Date: Thu, 13 Aug 2026 16:31:35 +0200 Subject: [PATCH 2/3] Rename service_operations_update_in_progress_cleanup to service_operations_update_stuck_in_progress_failed --- ...ce_operations_update_stuck_in_progress_failed.rb} | 12 ++++++------ config/cloud_controller.yml | 2 +- lib/cloud_controller/clock/scheduler.rb | 2 +- lib/cloud_controller/config_schemas/clock_schema.rb | 2 +- lib/cloud_controller/jobs.rb | 2 +- ...erations_update_stuck_in_progress_failed_spec.rb} | 11 ++++++----- .../lib/cloud_controller/clock/scheduler_spec.rb | 8 ++++---- 7 files changed, 20 insertions(+), 19 deletions(-) rename app/jobs/runtime/{service_operations_update_in_progress_cleanup.rb => service_operations_update_stuck_in_progress_failed.rb} (85%) rename spec/unit/jobs/runtime/{service_operations_update_in_progress_cleanup_spec.rb => service_operations_update_stuck_in_progress_failed_spec.rb} (93%) diff --git a/app/jobs/runtime/service_operations_update_in_progress_cleanup.rb b/app/jobs/runtime/service_operations_update_stuck_in_progress_failed.rb similarity index 85% rename from app/jobs/runtime/service_operations_update_in_progress_cleanup.rb rename to app/jobs/runtime/service_operations_update_stuck_in_progress_failed.rb index 867b8656762..8e57005bbe3 100644 --- a/app/jobs/runtime/service_operations_update_in_progress_cleanup.rb +++ b/app/jobs/runtime/service_operations_update_stuck_in_progress_failed.rb @@ -1,12 +1,12 @@ module VCAP::CloudController module Jobs module Runtime - class ServiceOperationsUpdateInProgressCleanup < VCAP::CloudController::Jobs::CCJob + class ServiceOperationsUpdateStuckInProgressFailed < VCAP::CloudController::Jobs::CCJob BATCH_SIZE = 10 def perform - logger.info("Cleaning up service 'update' operations stuck in 'in progress'") - cleanup_operations(ServiceInstanceOperation, ServiceInstance, :service_instance_id, 'service_instance.update') + logger.info("Marking stuck service 'update' operations as 'failed'") + mark_stuck_in_progress_failed(ServiceInstanceOperation, ServiceInstance, :service_instance_id, 'service_instance.update') end def max_attempts @@ -15,7 +15,7 @@ def max_attempts private - def cleanup_operations(operation_model, instance_model, foreign_key, jobs_operation) + def mark_stuck_in_progress_failed(operation_model, instance_model, foreign_key, jobs_operation) operation_table = operation_model.table_name instance_table = instance_model.table_name @@ -72,11 +72,11 @@ def default_maximum_duration_seconds end def logger - @logger ||= Steno.logger('cc.background.service-operations-update-in-progress-cleanup') + @logger ||= Steno.logger('cc.background.service-operations-update-stuck-in-progress-failed') end def job_name_in_configuration - :service_operations_update_in_progress_cleanup + :service_operations_update_stuck_in_progress_failed end end end diff --git a/config/cloud_controller.yml b/config/cloud_controller.yml index d8ea9fd2cd9..4903644b923 100644 --- a/config/cloud_controller.yml +++ b/config/cloud_controller.yml @@ -58,7 +58,7 @@ service_operations_initial_cleanup: service_operations_create_in_progress_cleanup: frequency_in_seconds: 3600 #1h -service_operations_update_in_progress_cleanup: +service_operations_update_stuck_in_progress_failed: frequency_in_seconds: 3600 #1h # One-off backfill - to be removed in a future version. diff --git a/lib/cloud_controller/clock/scheduler.rb b/lib/cloud_controller/clock/scheduler.rb index 65487ab962d..5b9f611cca2 100644 --- a/lib/cloud_controller/clock/scheduler.rb +++ b/lib/cloud_controller/clock/scheduler.rb @@ -26,7 +26,7 @@ class Scheduler { name: 'failed_jobs', class: Jobs::Runtime::FailedJobsCleanup }, { name: 'service_operations_initial_cleanup', class: Jobs::Runtime::ServiceOperationsInitialCleanup }, { name: 'service_operations_create_in_progress_cleanup', class: Jobs::Runtime::ServiceOperationsCreateInProgressCleanup }, - { name: 'service_operations_update_in_progress_cleanup', class: Jobs::Runtime::ServiceOperationsUpdateInProgressCleanup }, + { name: 'service_operations_update_stuck_in_progress_failed', class: Jobs::Runtime::ServiceOperationsUpdateStuckInProgressFailed }, # One-off backfill - to be removed in a future version. { name: 'lifecycle_type_backfill', class: Jobs::Runtime::LifecycleTypeBackfill } ].freeze diff --git a/lib/cloud_controller/config_schemas/clock_schema.rb b/lib/cloud_controller/config_schemas/clock_schema.rb index e5be2b4382e..bdd373ce55f 100644 --- a/lib/cloud_controller/config_schemas/clock_schema.rb +++ b/lib/cloud_controller/config_schemas/clock_schema.rb @@ -37,7 +37,7 @@ class ClockSchema < VCAP::Config service_operations_create_in_progress_cleanup: { frequency_in_seconds: Integer }, - service_operations_update_in_progress_cleanup: { + service_operations_update_stuck_in_progress_failed: { frequency_in_seconds: Integer }, # One-off backfill - to be removed in a future version. diff --git a/lib/cloud_controller/jobs.rb b/lib/cloud_controller/jobs.rb index 3abec61584b..253ae3d7e55 100644 --- a/lib/cloud_controller/jobs.rb +++ b/lib/cloud_controller/jobs.rb @@ -26,7 +26,7 @@ require 'jobs/runtime/expired_orphaned_blob_cleanup' require 'jobs/runtime/expired_resource_cleanup' require 'jobs/runtime/service_operations_create_in_progress_cleanup' -require 'jobs/runtime/service_operations_update_in_progress_cleanup' +require 'jobs/runtime/service_operations_update_stuck_in_progress_failed' require 'jobs/runtime/failed_jobs_cleanup' require 'jobs/runtime/service_operations_initial_cleanup' require 'jobs/runtime/legacy_jobs' diff --git a/spec/unit/jobs/runtime/service_operations_update_in_progress_cleanup_spec.rb b/spec/unit/jobs/runtime/service_operations_update_stuck_in_progress_failed_spec.rb similarity index 93% rename from spec/unit/jobs/runtime/service_operations_update_in_progress_cleanup_spec.rb rename to spec/unit/jobs/runtime/service_operations_update_stuck_in_progress_failed_spec.rb index a7f7668cab8..065d8032ab1 100644 --- a/spec/unit/jobs/runtime/service_operations_update_in_progress_cleanup_spec.rb +++ b/spec/unit/jobs/runtime/service_operations_update_stuck_in_progress_failed_spec.rb @@ -2,8 +2,8 @@ module VCAP::CloudController module Jobs::Runtime - RSpec.describe ServiceOperationsUpdateInProgressCleanup, job_context: :worker do - subject(:job) { ServiceOperationsUpdateInProgressCleanup.new } + RSpec.describe ServiceOperationsUpdateStuckInProgressFailed, job_context: :worker do + subject(:job) { ServiceOperationsUpdateStuckInProgressFailed.new } let(:fake_logger) { instance_double(Steno::Logger, info: nil, warn: nil) } let(:max_poll_duration_minutes) { 60 } @@ -50,9 +50,10 @@ def prepare_stuck_service_instance( shared_examples 'does not resolve the operation' do it 'leaves the operation in progress and the pollable job untouched' do scenario = subject_scenario + original_pollable_state = scenario[:pjob].state job.perform expect(scenario[:service_instance].last_operation.reload.state).to eq('in progress') - expect(scenario[:pjob].reload.state).to eq(scenario[:pjob].state) + expect(scenario[:pjob].reload.state).to eq(original_pollable_state) end end @@ -137,9 +138,9 @@ def prepare_stuck_service_instance( context 'when there are more stuck jobs than the batch size' do it 'processes only up to BATCH_SIZE jobs per run' do - (ServiceOperationsUpdateInProgressCleanup::BATCH_SIZE + 1).times { prepare_stuck_service_instance } + (ServiceOperationsUpdateStuckInProgressFailed::BATCH_SIZE + 1).times { prepare_stuck_service_instance } job.perform - expect(ServiceInstanceOperation.where(state: 'failed').count).to eq(ServiceOperationsUpdateInProgressCleanup::BATCH_SIZE) + expect(ServiceInstanceOperation.where(state: 'failed').count).to eq(ServiceOperationsUpdateStuckInProgressFailed::BATCH_SIZE) end end end diff --git a/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb b/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb index 8ef5921e333..849493ca28a 100644 --- a/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb +++ b/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb @@ -22,7 +22,7 @@ module VCAP::CloudController pollable_jobs: { cutoff_age_in_days: 2 }, service_operations_initial_cleanup: { frequency_in_seconds: 600 }, service_operations_create_in_progress_cleanup: { frequency_in_seconds: 600 }, - service_operations_update_in_progress_cleanup: { frequency_in_seconds: 600 }, + service_operations_update_stuck_in_progress_failed: { frequency_in_seconds: 600 }, lifecycle_type_backfill: { frequency_in_seconds: 500 }, service_usage_events: { cutoff_age_in_days: 5 }, completed_tasks: { cutoff_age_in_days: 6 }, @@ -171,9 +171,9 @@ module VCAP::CloudController end expect(clock).to receive(:schedule_frequent_worker_job) do |args, &block| - expect(args).to eql(name: 'service_operations_update_in_progress_cleanup', interval: 600) - expect(Jobs::Runtime::ServiceOperationsUpdateInProgressCleanup).to receive(:new).and_call_original - expect(block.call).to be_instance_of(Jobs::Runtime::ServiceOperationsUpdateInProgressCleanup) + expect(args).to eql(name: 'service_operations_update_stuck_in_progress_failed', interval: 600) + expect(Jobs::Runtime::ServiceOperationsUpdateStuckInProgressFailed).to receive(:new).and_call_original + expect(block.call).to be_instance_of(Jobs::Runtime::ServiceOperationsUpdateStuckInProgressFailed) end expect(clock).to receive(:schedule_frequent_worker_job) do |args, &block| From 374e2dc32074af9b9935a7cbe5f761da3fa5d6fc Mon Sep 17 00:00:00 2001 From: Katharina Przybill <30441792+kathap@users.noreply.github.com> Date: Fri, 14 Aug 2026 11:30:39 +0200 Subject: [PATCH 3/3] Retry stuck service delete operations via new clock job Add ServiceOperationsDeleteStuckInProgressRetry, a periodic clock job that detects service-instance delete operations stuck in 'in progress' (broker still working, CC polling job permanently failed after a transient DB error) and re-enqueues the original delete polling job instead of marking it failed. The failed delayed_job's serialized handler is reused, preserving the original user_audit_info and start_time so the ReoccurringJob max-duration expiry still marks the operation failed once the original polling window elapses. No orphan mitigation, since delete targets a resource that should be removed. --- ...erations_delete_stuck_in_progress_retry.rb | 108 ++++++++++ config/cloud_controller.yml | 3 + lib/cloud_controller/clock/scheduler.rb | 1 + .../config_schemas/clock_schema.rb | 3 + lib/cloud_controller/jobs.rb | 1 + ...ons_delete_stuck_in_progress_retry_spec.rb | 199 ++++++++++++++++++ .../cloud_controller/clock/scheduler_spec.rb | 7 + 7 files changed, 322 insertions(+) create mode 100644 app/jobs/runtime/service_operations_delete_stuck_in_progress_retry.rb create mode 100644 spec/unit/jobs/runtime/service_operations_delete_stuck_in_progress_retry_spec.rb diff --git a/app/jobs/runtime/service_operations_delete_stuck_in_progress_retry.rb b/app/jobs/runtime/service_operations_delete_stuck_in_progress_retry.rb new file mode 100644 index 00000000000..a08b1f8bd40 --- /dev/null +++ b/app/jobs/runtime/service_operations_delete_stuck_in_progress_retry.rb @@ -0,0 +1,108 @@ +module VCAP::CloudController + module Jobs + module Runtime + class ServiceOperationsDeleteStuckInProgressRetry < VCAP::CloudController::Jobs::CCJob + BATCH_SIZE = 10 + + def perform + logger.info("Retrying stuck service 'delete' operations") + retry_stuck(ServiceInstanceOperation, ServiceInstance, :service_instance_id, 'service_instance.delete') + end + + def max_attempts + 1 + end + + private + + def retry_stuck(operation_model, instance_model, foreign_key, jobs_operation) + # Find stuck service instance 'delete' operations where the broker may still be working + # but CC's polling job has permanently failed due to a transient error (e.g. brief db connection flip). + # + # Unlike create/update we do not mark the operation failed: for a delete we re-enqueue the original + # polling job so the deprovision is driven to completion. The original delayed_job's serialized handler + # is reused, preserving @start_time so the ReoccurringJob max-duration expiry (which marks the operation + # failed via handle_timeout) still fires against the original polling window. + operation_table = operation_model.table_name + instance_table = instance_model.table_name + + stuck = operation_model. + join(instance_table, id: Sequel[operation_table][foreign_key]). + join(:jobs, resource_guid: Sequel[instance_table][:guid]). + join(:delayed_jobs, guid: Sequel[:jobs][:delayed_job_guid]). + where(Sequel[operation_table][:state] => 'in progress'). + where(Sequel[operation_table][:type] => 'delete'). + where(Sequel.lit("#{operation_table}.created_at > CURRENT_TIMESTAMP - INTERVAL '?' SECOND", default_maximum_duration_seconds.to_i)). + where(Sequel[:jobs][:state] => [PollableJobModel::POLLING_STATE, PollableJobModel::FAILED_STATE]). + where(Sequel[:jobs][:operation] => jobs_operation). + exclude(Sequel[:delayed_jobs][:failed_at] => nil). + select( + Sequel[:jobs][:guid].as(:pollable_guid), + Sequel[operation_table][:id].as(:op_id), + Sequel[operation_table][foreign_key].as(:resource_id) + ). + order(Sequel[operation_table][:created_at]). + limit(BATCH_SIZE) + + stuck.each do |row| + resolve_stuck(operation_model, instance_model, row[:op_id], row[:resource_id], row[:pollable_guid]) + end + end + + def resolve_stuck(operation_model, instance_model, op_id, resource_id, pollable_guid) + operation_model.db.transaction do + operation = operation_model.where(id: op_id, state: 'in progress').for_update.skip_locked.first + return unless operation + + instance = instance_model.first(id: resource_id) + return unless instance + + pollable = PollableJobModel.first(guid: pollable_guid) + return unless pollable + + handler = deserialize_handler(pollable) + return unless handler + + instance_type = instance_model.to_s.split('::').last + + logger.info( + "#{instance_type} #{instance.guid} delete operation is stuck in 'in progress'. Re-enqueuing the polling job.", + instance_type: instance_type, + instance_guid: instance.guid, + operation_id: op_id, + pollable_job_guid: pollable_guid + ) + + pollable.update(state: PollableJobModel::POLLING_STATE, cf_api_error: nil) + Jobs::GenericEnqueuer.shared.enqueue_pollable(handler, existing_guid: pollable.guid, preserve_priority: true) + end + end + + # Reuse the original delete polling job by deserializing the failed delayed_job's handler and unwrapping + # the wrapper chain (LoggingContextJob → TimeoutJob → PollableJobWrapper → DeleteServiceInstanceJob). + # This preserves the original @user_audit_info, @start_time and the recursive-vs-plain delete variant. + def deserialize_handler(pollable) + delayed_job = Delayed::Job[guid: pollable.delayed_job_guid] + return unless delayed_job + + Jobs::Enqueuer.unwrap_job(delayed_job.payload_object) + rescue StandardError => e + logger.error("Could not deserialize delayed job '#{pollable.delayed_job_guid}' for pollable '#{pollable.guid}': #{e.class}: #{e.message}") + nil + end + + def default_maximum_duration_seconds + Config.config.get(:broker_client_max_async_poll_duration_minutes).minutes + end + + def logger + @logger ||= Steno.logger('cc.background.service-operations-delete-stuck-in-progress-retry') + end + + def job_name_in_configuration + :service_operations_delete_stuck_in_progress_retry + end + end + end + end +end diff --git a/config/cloud_controller.yml b/config/cloud_controller.yml index 4903644b923..1f1c5d861a7 100644 --- a/config/cloud_controller.yml +++ b/config/cloud_controller.yml @@ -61,6 +61,9 @@ service_operations_create_in_progress_cleanup: service_operations_update_stuck_in_progress_failed: frequency_in_seconds: 3600 #1h +service_operations_delete_stuck_in_progress_retry: + frequency_in_seconds: 3600 #1h + # One-off backfill - to be removed in a future version. lifecycle_type_backfill: frequency_in_seconds: 3600 #1h diff --git a/lib/cloud_controller/clock/scheduler.rb b/lib/cloud_controller/clock/scheduler.rb index 5b9f611cca2..84fb6cdff76 100644 --- a/lib/cloud_controller/clock/scheduler.rb +++ b/lib/cloud_controller/clock/scheduler.rb @@ -27,6 +27,7 @@ class Scheduler { name: 'service_operations_initial_cleanup', class: Jobs::Runtime::ServiceOperationsInitialCleanup }, { name: 'service_operations_create_in_progress_cleanup', class: Jobs::Runtime::ServiceOperationsCreateInProgressCleanup }, { name: 'service_operations_update_stuck_in_progress_failed', class: Jobs::Runtime::ServiceOperationsUpdateStuckInProgressFailed }, + { name: 'service_operations_delete_stuck_in_progress_retry', class: Jobs::Runtime::ServiceOperationsDeleteStuckInProgressRetry }, # One-off backfill - to be removed in a future version. { name: 'lifecycle_type_backfill', class: Jobs::Runtime::LifecycleTypeBackfill } ].freeze diff --git a/lib/cloud_controller/config_schemas/clock_schema.rb b/lib/cloud_controller/config_schemas/clock_schema.rb index bdd373ce55f..6f5fa94095c 100644 --- a/lib/cloud_controller/config_schemas/clock_schema.rb +++ b/lib/cloud_controller/config_schemas/clock_schema.rb @@ -40,6 +40,9 @@ class ClockSchema < VCAP::Config service_operations_update_stuck_in_progress_failed: { frequency_in_seconds: Integer }, + service_operations_delete_stuck_in_progress_retry: { + frequency_in_seconds: Integer + }, # One-off backfill - to be removed in a future version. lifecycle_type_backfill: { frequency_in_seconds: Integer diff --git a/lib/cloud_controller/jobs.rb b/lib/cloud_controller/jobs.rb index 253ae3d7e55..b7449b1fab1 100644 --- a/lib/cloud_controller/jobs.rb +++ b/lib/cloud_controller/jobs.rb @@ -27,6 +27,7 @@ require 'jobs/runtime/expired_resource_cleanup' require 'jobs/runtime/service_operations_create_in_progress_cleanup' require 'jobs/runtime/service_operations_update_stuck_in_progress_failed' +require 'jobs/runtime/service_operations_delete_stuck_in_progress_retry' require 'jobs/runtime/failed_jobs_cleanup' require 'jobs/runtime/service_operations_initial_cleanup' require 'jobs/runtime/legacy_jobs' diff --git a/spec/unit/jobs/runtime/service_operations_delete_stuck_in_progress_retry_spec.rb b/spec/unit/jobs/runtime/service_operations_delete_stuck_in_progress_retry_spec.rb new file mode 100644 index 00000000000..79f70339519 --- /dev/null +++ b/spec/unit/jobs/runtime/service_operations_delete_stuck_in_progress_retry_spec.rb @@ -0,0 +1,199 @@ +require 'spec_helper' + +module VCAP::CloudController + module Jobs::Runtime + RSpec.describe ServiceOperationsDeleteStuckInProgressRetry, job_context: :worker do + subject(:job) { ServiceOperationsDeleteStuckInProgressRetry.new } + + let(:fake_logger) { instance_double(Steno::Logger, info: nil, warn: nil, error: nil) } + let(:max_poll_duration_minutes) { 60 } + let(:user_audit_info) { UserAuditInfo.new(user_guid: create(:user).guid, user_email: 'foo@example.com') } + let(:enqueuer) { instance_double(Jobs::GenericEnqueuer, enqueue_pollable: nil) } + + before do + allow(Steno).to receive(:logger).and_return(fake_logger) + TestConfig.override(broker_client_max_async_poll_duration_minutes: max_poll_duration_minutes) + allow(Jobs::GenericEnqueuer).to receive(:shared).and_return(enqueuer) + end + + # Enqueue a real DeleteServiceInstanceJob so the delayed_job carries a genuine serialized handler, + # then simulate the permanent failure (failed_at set) that leaves the operation stuck in progress. + def prepare_stuck_service_instance( + service_instance_state: 'in progress', + service_instance_type: 'delete', + service_instance_created_at: Time.now, + pollable_job_state: PollableJobModel::FAILED_STATE, + pollable_job_operation: 'service_instance.delete', + delayed_job_failed_at: Time.now + ) + service_instance = create(:managed_service_instance) + + create(:service_instance_operation, + service_instance_id: service_instance.id, + type: service_instance_type, + state: service_instance_state, + created_at: service_instance_created_at) + + delete_job = V3::DeleteServiceInstanceJob.new(service_instance.guid, user_audit_info) + pjob = Jobs::Enqueuer.new(queue: Jobs::Queues.generic).enqueue_pollable(delete_job) + pjob.update(state: pollable_job_state, operation: pollable_job_operation) + + dj = Delayed::Job[guid: pjob.delayed_job_guid] + dj.update(failed_at: delayed_job_failed_at) + + { service_instance: service_instance, pjob: pjob, delayed_job: dj } + end + + shared_examples 'does not retry the operation' do + it 'leaves the operation in progress, the pollable job untouched, and does not re-enqueue' do + scenario = subject_scenario + original_pollable_state = scenario[:pjob].state + job.perform + expect(scenario[:service_instance].last_operation.reload.state).to eq('in progress') + expect(scenario[:pjob].reload.state).to eq(original_pollable_state) + expect(enqueuer).not_to have_received(:enqueue_pollable) + end + end + + it { is_expected.to be_a_valid_job } + + describe '#perform' do + context 'when sio state is not in progress' do + it 'does not retry when state is succeeded' do + scenario = prepare_stuck_service_instance(service_instance_state: 'succeeded') + job.perform + expect(scenario[:service_instance].last_operation.reload.state).to eq('succeeded') + expect(enqueuer).not_to have_received(:enqueue_pollable) + end + + it 'does not retry when state is failed' do + scenario = prepare_stuck_service_instance(service_instance_state: 'failed') + job.perform + expect(scenario[:service_instance].last_operation.reload.state).to eq('failed') + expect(enqueuer).not_to have_received(:enqueue_pollable) + end + end + + context 'when sio type is not delete' do + let(:subject_scenario) { prepare_stuck_service_instance(service_instance_type: 'update', pollable_job_operation: 'service_instance.update') } + + it_behaves_like 'does not retry the operation' + end + + context 'when sio created_at is beyond the max polling window' do + let(:subject_scenario) { prepare_stuck_service_instance(service_instance_created_at: Time.now - (max_poll_duration_minutes + 1).minutes) } + + it_behaves_like 'does not retry the operation' + end + + context 'when delayed_job.failed_at is nil (job still running or locked)' do + let(:subject_scenario) { prepare_stuck_service_instance(delayed_job_failed_at: nil) } + + it_behaves_like 'does not retry the operation' + end + + context 'when pollable job state is COMPLETE' do + let(:subject_scenario) { prepare_stuck_service_instance(pollable_job_state: PollableJobModel::COMPLETE_STATE) } + + it_behaves_like 'does not retry the operation' + end + + context 'when pollable job state is PROCESSING' do + let(:subject_scenario) { prepare_stuck_service_instance(pollable_job_state: PollableJobModel::PROCESSING_STATE) } + + it_behaves_like 'does not retry the operation' + end + + context 'when pollable job operation is not service_instance.delete' do + let(:subject_scenario) { prepare_stuck_service_instance(pollable_job_operation: 'service_instance.create') } + + it_behaves_like 'does not retry the operation' + end + + context 'when a service instance delete job is stuck with state FAILED' do + it 'resets the pollable job to POLLING and re-enqueues the original delete job' do + scenario = prepare_stuck_service_instance + job.perform + + expect(scenario[:service_instance].last_operation.reload.state).to eq('in progress') + expect(scenario[:pjob].reload.state).to eq(PollableJobModel::POLLING_STATE) + expect(enqueuer).to have_received(:enqueue_pollable).with( + an_instance_of(V3::DeleteServiceInstanceJob), + hash_including(existing_guid: scenario[:pjob].guid, preserve_priority: true) + ) + end + end + + context 'when a service instance delete job is stuck with state POLLING (DB flip before failure hook)' do + it 'resets the pollable job to POLLING and re-enqueues the original delete job' do + scenario = prepare_stuck_service_instance(pollable_job_state: PollableJobModel::POLLING_STATE) + job.perform + + expect(scenario[:pjob].reload.state).to eq(PollableJobModel::POLLING_STATE) + expect(enqueuer).to have_received(:enqueue_pollable).with( + an_instance_of(V3::DeleteServiceInstanceJob), + hash_including(existing_guid: scenario[:pjob].guid) + ) + end + end + + context 'when there are multiple stuck jobs within the batch size' do + it 'retries each one' do + 3.times { prepare_stuck_service_instance } + job.perform + expect(enqueuer).to have_received(:enqueue_pollable).exactly(3).times + end + end + + context 'when there are more stuck jobs than the batch size' do + it 'processes only up to BATCH_SIZE jobs per run' do + (ServiceOperationsDeleteStuckInProgressRetry::BATCH_SIZE + 1).times { prepare_stuck_service_instance } + job.perform + expect(enqueuer).to have_received(:enqueue_pollable).exactly(ServiceOperationsDeleteStuckInProgressRetry::BATCH_SIZE).times + end + end + end + + describe '#resolve_stuck' do + context 'when another process already resolved it (skip_locked returns nil)' do + it 'does nothing and does not re-enqueue' do + scenario = prepare_stuck_service_instance + + expect do + job.send(:resolve_stuck, ServiceInstanceOperation, ServiceInstance, + -1, scenario[:service_instance].id, scenario[:pjob].guid) + end.not_to raise_error + expect(scenario[:pjob].reload.state).to eq(PollableJobModel::FAILED_STATE) + expect(enqueuer).not_to have_received(:enqueue_pollable) + end + end + + context 'when the delayed job handler cannot be deserialized' do + it 'does not re-enqueue and leaves the pollable job untouched' do + scenario = prepare_stuck_service_instance + Delayed::Job[guid: scenario[:pjob].delayed_job_guid].update(handler: 'not-valid-yaml: ]') + op = scenario[:service_instance].last_operation + + job.send(:resolve_stuck, ServiceInstanceOperation, ServiceInstance, + op.id, scenario[:service_instance].id, scenario[:pjob].guid) + + expect(scenario[:pjob].reload.state).to eq(PollableJobModel::FAILED_STATE) + expect(enqueuer).not_to have_received(:enqueue_pollable) + end + end + + context 'when the operation is stuck in progress' do + it 'resets the pollable job from its failed state to POLLING' do + scenario = prepare_stuck_service_instance + op = scenario[:service_instance].last_operation + + expect do + job.send(:resolve_stuck, ServiceInstanceOperation, ServiceInstance, + op.id, scenario[:service_instance].id, scenario[:pjob].guid) + end.to change { scenario[:pjob].reload.state }.from(PollableJobModel::FAILED_STATE).to(PollableJobModel::POLLING_STATE) + end + end + end + end + end +end diff --git a/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb b/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb index 849493ca28a..05f6521a36e 100644 --- a/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb +++ b/spec/unit/lib/cloud_controller/clock/scheduler_spec.rb @@ -23,6 +23,7 @@ module VCAP::CloudController service_operations_initial_cleanup: { frequency_in_seconds: 600 }, service_operations_create_in_progress_cleanup: { frequency_in_seconds: 600 }, service_operations_update_stuck_in_progress_failed: { frequency_in_seconds: 600 }, + service_operations_delete_stuck_in_progress_retry: { frequency_in_seconds: 600 }, lifecycle_type_backfill: { frequency_in_seconds: 500 }, service_usage_events: { cutoff_age_in_days: 5 }, completed_tasks: { cutoff_age_in_days: 6 }, @@ -176,6 +177,12 @@ module VCAP::CloudController expect(block.call).to be_instance_of(Jobs::Runtime::ServiceOperationsUpdateStuckInProgressFailed) end + expect(clock).to receive(:schedule_frequent_worker_job) do |args, &block| + expect(args).to eql(name: 'service_operations_delete_stuck_in_progress_retry', interval: 600) + expect(Jobs::Runtime::ServiceOperationsDeleteStuckInProgressRetry).to receive(:new).and_call_original + expect(block.call).to be_instance_of(Jobs::Runtime::ServiceOperationsDeleteStuckInProgressRetry) + end + expect(clock).to receive(:schedule_frequent_worker_job) do |args, &block| expect(args).to eql(name: 'lifecycle_type_backfill', interval: 500) expect(Jobs::Runtime::LifecycleTypeBackfill).to receive(:new).and_call_original