Skip to content

Commit a6af7aa

Browse files
committed
Add job to retry stuck service binding delete operations
Detect credential-binding and service-key delete operations stuck in 'in progress' with a permanently-failed polling job, and internally retry by re-enqueuing the original DeleteBindingJob. Mirrors the existing service-instance delete-retry job. Route bindings are skipped.
1 parent 374e2dc commit a6af7aa

7 files changed

Lines changed: 345 additions & 0 deletions

File tree

Lines changed: 109 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,109 @@
1+
module VCAP::CloudController
2+
module Jobs
3+
module Runtime
4+
class ServiceOperationsBindingDeleteStuckInProgressRetry < VCAP::CloudController::Jobs::CCJob
5+
BATCH_SIZE = 10
6+
7+
def perform
8+
logger.info("Retrying stuck binding 'delete' operations")
9+
retry_stuck(ServiceBindingOperation, ServiceBinding, :service_binding_id, 'service_bindings.delete')
10+
retry_stuck(ServiceKeyOperation, ServiceKey, :service_key_id, 'service_keys.delete')
11+
end
12+
13+
def max_attempts
14+
1
15+
end
16+
17+
private
18+
19+
def retry_stuck(operation_model, instance_model, foreign_key, jobs_operation)
20+
# Find stuck binding 'delete' operations where the broker may still be working
21+
# but CC's polling job has permanently failed due to a transient error (e.g. brief db connection flip).
22+
#
23+
# Unlike create we do not mark the operation failed and do not mitigate orphans: for a delete we
24+
# re-enqueue the original polling job so the unbind is driven to completion. The original delayed_job's
25+
# serialized handler is reused, preserving @start_time so the ReoccurringJob max-duration expiry
26+
# (which marks the operation failed via handle_timeout) still fires against the original polling window.
27+
operation_table = operation_model.table_name
28+
instance_table = instance_model.table_name
29+
30+
stuck = operation_model.
31+
join(instance_table, id: Sequel[operation_table][foreign_key]).
32+
join(:jobs, resource_guid: Sequel[instance_table][:guid]).
33+
join(:delayed_jobs, guid: Sequel[:jobs][:delayed_job_guid]).
34+
where(Sequel[operation_table][:state] => 'in progress').
35+
where(Sequel[operation_table][:type] => 'delete').
36+
where(Sequel.lit("#{operation_table}.created_at > CURRENT_TIMESTAMP - INTERVAL '?' SECOND", default_maximum_duration_seconds.to_i)).
37+
where(Sequel[:jobs][:state] => [PollableJobModel::POLLING_STATE, PollableJobModel::FAILED_STATE]).
38+
where(Sequel[:jobs][:operation] => jobs_operation).
39+
exclude(Sequel[:delayed_jobs][:failed_at] => nil).
40+
select(
41+
Sequel[:jobs][:guid].as(:pollable_guid),
42+
Sequel[operation_table][:id].as(:op_id),
43+
Sequel[operation_table][foreign_key].as(:resource_id)
44+
).
45+
order(Sequel[operation_table][:created_at]).
46+
limit(BATCH_SIZE)
47+
48+
stuck.each do |row|
49+
resolve_stuck(operation_model, instance_model, row[:op_id], row[:resource_id], row[:pollable_guid])
50+
end
51+
end
52+
53+
def resolve_stuck(operation_model, instance_model, op_id, resource_id, pollable_guid)
54+
operation_model.db.transaction do
55+
operation = operation_model.where(id: op_id, state: 'in progress').for_update.skip_locked.first
56+
return unless operation
57+
58+
binding = instance_model.first(id: resource_id)
59+
return unless binding
60+
61+
pollable = PollableJobModel.first(guid: pollable_guid)
62+
return unless pollable
63+
64+
handler = deserialize_handler(pollable)
65+
return unless handler
66+
67+
binding_type = instance_model.to_s.split('::').last
68+
69+
logger.info(
70+
"#{binding_type} #{binding.guid} delete operation is stuck in 'in progress'. Re-enqueuing the polling job.",
71+
binding_type: binding_type,
72+
binding_guid: binding.guid,
73+
operation_id: op_id,
74+
pollable_job_guid: pollable_guid
75+
)
76+
77+
pollable.update(state: PollableJobModel::POLLING_STATE, cf_api_error: nil)
78+
Jobs::GenericEnqueuer.shared.enqueue_pollable(handler, existing_guid: pollable.guid, preserve_priority: true)
79+
end
80+
end
81+
82+
# Reuse the original delete polling job by deserializing the failed delayed_job's handler and unwrapping
83+
# the wrapper chain (LoggingContextJob → TimeoutJob → PollableJobWrapper → DeleteBindingJob).
84+
# This preserves the original @user_audit_info, @start_time and the binding @type.
85+
def deserialize_handler(pollable)
86+
delayed_job = Delayed::Job[guid: pollable.delayed_job_guid]
87+
return unless delayed_job
88+
89+
Jobs::Enqueuer.unwrap_job(delayed_job.payload_object)
90+
rescue StandardError => e
91+
logger.error("Could not deserialize delayed job '#{pollable.delayed_job_guid}' for pollable '#{pollable.guid}': #{e.class}: #{e.message}")
92+
nil
93+
end
94+
95+
def default_maximum_duration_seconds
96+
Config.config.get(:broker_client_max_async_poll_duration_minutes).minutes
97+
end
98+
99+
def logger
100+
@logger ||= Steno.logger('cc.background.service-operations-binding-delete-stuck-in-progress-retry')
101+
end
102+
103+
def job_name_in_configuration
104+
:service_operations_binding_delete_stuck_in_progress_retry
105+
end
106+
end
107+
end
108+
end
109+
end

config/cloud_controller.yml

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -64,6 +64,9 @@ service_operations_update_stuck_in_progress_failed:
6464
service_operations_delete_stuck_in_progress_retry:
6565
frequency_in_seconds: 3600 #1h
6666

67+
service_operations_binding_delete_stuck_in_progress_retry:
68+
frequency_in_seconds: 3600 #1h
69+
6770
# One-off backfill - to be removed in a future version.
6871
lifecycle_type_backfill:
6972
frequency_in_seconds: 3600 #1h

lib/cloud_controller/clock/scheduler.rb

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@ class Scheduler
2828
{ name: 'service_operations_create_in_progress_cleanup', class: Jobs::Runtime::ServiceOperationsCreateInProgressCleanup },
2929
{ name: 'service_operations_update_stuck_in_progress_failed', class: Jobs::Runtime::ServiceOperationsUpdateStuckInProgressFailed },
3030
{ name: 'service_operations_delete_stuck_in_progress_retry', class: Jobs::Runtime::ServiceOperationsDeleteStuckInProgressRetry },
31+
{ name: 'service_operations_binding_delete_stuck_in_progress_retry', class: Jobs::Runtime::ServiceOperationsBindingDeleteStuckInProgressRetry },
3132
# One-off backfill - to be removed in a future version.
3233
{ name: 'lifecycle_type_backfill', class: Jobs::Runtime::LifecycleTypeBackfill }
3334
].freeze

lib/cloud_controller/config_schemas/clock_schema.rb

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -43,6 +43,9 @@ class ClockSchema < VCAP::Config
4343
service_operations_delete_stuck_in_progress_retry: {
4444
frequency_in_seconds: Integer
4545
},
46+
service_operations_binding_delete_stuck_in_progress_retry: {
47+
frequency_in_seconds: Integer
48+
},
4649
# One-off backfill - to be removed in a future version.
4750
lifecycle_type_backfill: {
4851
frequency_in_seconds: Integer

lib/cloud_controller/jobs.rb

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@
2828
require 'jobs/runtime/service_operations_create_in_progress_cleanup'
2929
require 'jobs/runtime/service_operations_update_stuck_in_progress_failed'
3030
require 'jobs/runtime/service_operations_delete_stuck_in_progress_retry'
31+
require 'jobs/runtime/service_operations_binding_delete_stuck_in_progress_retry'
3132
require 'jobs/runtime/failed_jobs_cleanup'
3233
require 'jobs/runtime/service_operations_initial_cleanup'
3334
require 'jobs/runtime/legacy_jobs'
Lines changed: 221 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,221 @@
1+
require 'spec_helper'
2+
3+
module VCAP::CloudController
4+
module Jobs::Runtime
5+
RSpec.describe ServiceOperationsBindingDeleteStuckInProgressRetry, job_context: :worker do
6+
subject(:job) { ServiceOperationsBindingDeleteStuckInProgressRetry.new }
7+
8+
let(:fake_logger) { instance_double(Steno::Logger, info: nil, warn: nil, error: nil) }
9+
let(:max_poll_duration_minutes) { 60 }
10+
let(:user_audit_info) { UserAuditInfo.new(user_guid: create(:user).guid, user_email: 'foo@example.com') }
11+
let(:enqueuer) { instance_double(Jobs::GenericEnqueuer, enqueue_pollable: nil) }
12+
13+
before do
14+
allow(Steno).to receive(:logger).and_return(fake_logger)
15+
TestConfig.override(broker_client_max_async_poll_duration_minutes: max_poll_duration_minutes)
16+
allow(Jobs::GenericEnqueuer).to receive(:shared).and_return(enqueuer)
17+
end
18+
19+
# Enqueue a real DeleteBindingJob so the delayed_job carries a genuine serialized handler,
20+
# then simulate the permanent failure (failed_at set) that leaves the operation stuck in progress.
21+
def prepare_stuck_binding(
22+
binding_type:,
23+
operation_state: 'in progress',
24+
operation_type: 'delete',
25+
operation_created_at: Time.now,
26+
pollable_job_state: PollableJobModel::FAILED_STATE,
27+
pollable_job_operation: nil,
28+
delayed_job_failed_at: Time.now
29+
)
30+
if binding_type == :credential
31+
binding = create(:service_binding)
32+
create(:service_binding_operation, service_binding_id: binding.id, type: operation_type, state: operation_state, created_at: operation_created_at)
33+
default_operation = 'service_bindings.delete'
34+
resource_type = 'service_bindings'
35+
else
36+
binding = create(:service_key)
37+
create(:service_key_operation, service_key_id: binding.id, type: operation_type, state: operation_state, created_at: operation_created_at)
38+
default_operation = 'service_keys.delete'
39+
resource_type = 'service_keys'
40+
end
41+
42+
delete_job = V3::DeleteBindingJob.new(binding_type, binding.guid, user_audit_info: user_audit_info)
43+
pjob = Jobs::Enqueuer.new(queue: Jobs::Queues.generic).enqueue_pollable(delete_job)
44+
pjob.update(state: pollable_job_state, operation: pollable_job_operation || default_operation, resource_type: resource_type)
45+
46+
dj = Delayed::Job[guid: pjob.delayed_job_guid]
47+
dj.update(failed_at: delayed_job_failed_at)
48+
49+
{ binding: binding, pjob: pjob, delayed_job: dj }
50+
end
51+
52+
it { is_expected.to be_a_valid_job }
53+
54+
%i[credential key].each do |binding_type|
55+
describe "#perform for #{binding_type} bindings" do
56+
shared_examples 'does not retry the operation' do
57+
it 'leaves the operation in progress, the pollable job untouched, and does not re-enqueue' do
58+
scenario = subject_scenario
59+
original_pollable_state = scenario[:pjob].state
60+
job.perform
61+
expect(scenario[:binding].last_operation.reload.state).to eq('in progress')
62+
expect(scenario[:pjob].reload.state).to eq(original_pollable_state)
63+
expect(enqueuer).not_to have_received(:enqueue_pollable)
64+
end
65+
end
66+
67+
context 'when operation state is not in progress' do
68+
it 'does not retry when state is succeeded' do
69+
scenario = prepare_stuck_binding(binding_type: binding_type, operation_state: 'succeeded')
70+
job.perform
71+
expect(scenario[:binding].last_operation.reload.state).to eq('succeeded')
72+
expect(enqueuer).not_to have_received(:enqueue_pollable)
73+
end
74+
75+
it 'does not retry when state is failed' do
76+
scenario = prepare_stuck_binding(binding_type: binding_type, operation_state: 'failed')
77+
job.perform
78+
expect(scenario[:binding].last_operation.reload.state).to eq('failed')
79+
expect(enqueuer).not_to have_received(:enqueue_pollable)
80+
end
81+
end
82+
83+
context 'when operation type is not delete' do
84+
let(:subject_scenario) do
85+
prepare_stuck_binding(binding_type: binding_type, operation_type: 'create',
86+
pollable_job_operation: binding_type == :credential ? 'service_bindings.create' : 'service_keys.create')
87+
end
88+
89+
it_behaves_like 'does not retry the operation'
90+
end
91+
92+
context 'when operation created_at is beyond the max polling window' do
93+
let(:subject_scenario) { prepare_stuck_binding(binding_type: binding_type, operation_created_at: Time.now - (max_poll_duration_minutes + 1).minutes) }
94+
95+
it_behaves_like 'does not retry the operation'
96+
end
97+
98+
context 'when delayed_job.failed_at is nil (job still running or locked)' do
99+
let(:subject_scenario) { prepare_stuck_binding(binding_type: binding_type, delayed_job_failed_at: nil) }
100+
101+
it_behaves_like 'does not retry the operation'
102+
end
103+
104+
context 'when pollable job state is COMPLETE' do
105+
let(:subject_scenario) { prepare_stuck_binding(binding_type: binding_type, pollable_job_state: PollableJobModel::COMPLETE_STATE) }
106+
107+
it_behaves_like 'does not retry the operation'
108+
end
109+
110+
context 'when pollable job state is PROCESSING' do
111+
let(:subject_scenario) { prepare_stuck_binding(binding_type: binding_type, pollable_job_state: PollableJobModel::PROCESSING_STATE) }
112+
113+
it_behaves_like 'does not retry the operation'
114+
end
115+
116+
context 'when pollable job operation does not match the delete operation' do
117+
let(:subject_scenario) do
118+
prepare_stuck_binding(binding_type: binding_type,
119+
pollable_job_operation: binding_type == :credential ? 'service_bindings.create' : 'service_keys.create')
120+
end
121+
122+
it_behaves_like 'does not retry the operation'
123+
end
124+
125+
context 'when a binding delete job is stuck with state FAILED' do
126+
it 'resets the pollable job to POLLING and re-enqueues the original delete job' do
127+
scenario = prepare_stuck_binding(binding_type: binding_type)
128+
job.perform
129+
130+
expect(scenario[:binding].last_operation.reload.state).to eq('in progress')
131+
expect(scenario[:pjob].reload.state).to eq(PollableJobModel::POLLING_STATE)
132+
expect(enqueuer).to have_received(:enqueue_pollable).with(
133+
an_instance_of(V3::DeleteBindingJob),
134+
hash_including(existing_guid: scenario[:pjob].guid, preserve_priority: true)
135+
)
136+
end
137+
end
138+
139+
context 'when a binding delete job is stuck with state POLLING (DB flip before failure hook)' do
140+
it 'resets the pollable job to POLLING and re-enqueues the original delete job' do
141+
scenario = prepare_stuck_binding(binding_type: binding_type, pollable_job_state: PollableJobModel::POLLING_STATE)
142+
job.perform
143+
144+
expect(scenario[:pjob].reload.state).to eq(PollableJobModel::POLLING_STATE)
145+
expect(enqueuer).to have_received(:enqueue_pollable).with(
146+
an_instance_of(V3::DeleteBindingJob),
147+
hash_including(existing_guid: scenario[:pjob].guid)
148+
)
149+
end
150+
end
151+
152+
context 'when there are multiple stuck jobs within the batch size' do
153+
it 'retries each one' do
154+
3.times { prepare_stuck_binding(binding_type: binding_type) }
155+
job.perform
156+
expect(enqueuer).to have_received(:enqueue_pollable).exactly(3).times
157+
end
158+
end
159+
160+
context 'when there are more stuck jobs than the batch size' do
161+
it 'processes only up to BATCH_SIZE jobs per run' do
162+
(ServiceOperationsBindingDeleteStuckInProgressRetry::BATCH_SIZE + 1).times { prepare_stuck_binding(binding_type: binding_type) }
163+
job.perform
164+
expect(enqueuer).to have_received(:enqueue_pollable).exactly(ServiceOperationsBindingDeleteStuckInProgressRetry::BATCH_SIZE).times
165+
end
166+
end
167+
end
168+
end
169+
170+
describe '#perform cross-type isolation' do
171+
it 'retries both a stuck credential-binding delete and a stuck key delete' do
172+
prepare_stuck_binding(binding_type: :credential)
173+
prepare_stuck_binding(binding_type: :key)
174+
job.perform
175+
expect(enqueuer).to have_received(:enqueue_pollable).exactly(2).times
176+
end
177+
end
178+
179+
describe '#resolve_stuck' do
180+
context 'when another process already resolved it (skip_locked returns nil)' do
181+
it 'does nothing and does not re-enqueue' do
182+
scenario = prepare_stuck_binding(binding_type: :credential)
183+
184+
expect do
185+
job.send(:resolve_stuck, ServiceBindingOperation, ServiceBinding,
186+
-1, scenario[:binding].id, scenario[:pjob].guid)
187+
end.not_to raise_error
188+
expect(scenario[:pjob].reload.state).to eq(PollableJobModel::FAILED_STATE)
189+
expect(enqueuer).not_to have_received(:enqueue_pollable)
190+
end
191+
end
192+
193+
context 'when the delayed job handler cannot be deserialized' do
194+
it 'does not re-enqueue and leaves the pollable job untouched' do
195+
scenario = prepare_stuck_binding(binding_type: :credential)
196+
Delayed::Job[guid: scenario[:pjob].delayed_job_guid].update(handler: 'not-valid-yaml: ]')
197+
op = scenario[:binding].last_operation
198+
199+
job.send(:resolve_stuck, ServiceBindingOperation, ServiceBinding,
200+
op.id, scenario[:binding].id, scenario[:pjob].guid)
201+
202+
expect(scenario[:pjob].reload.state).to eq(PollableJobModel::FAILED_STATE)
203+
expect(enqueuer).not_to have_received(:enqueue_pollable)
204+
end
205+
end
206+
207+
context 'when the operation is stuck in progress' do
208+
it 'resets the pollable job from its failed state to POLLING' do
209+
scenario = prepare_stuck_binding(binding_type: :credential)
210+
op = scenario[:binding].last_operation
211+
212+
expect do
213+
job.send(:resolve_stuck, ServiceBindingOperation, ServiceBinding,
214+
op.id, scenario[:binding].id, scenario[:pjob].guid)
215+
end.to change { scenario[:pjob].reload.state }.from(PollableJobModel::FAILED_STATE).to(PollableJobModel::POLLING_STATE)
216+
end
217+
end
218+
end
219+
end
220+
end
221+
end

spec/unit/lib/cloud_controller/clock/scheduler_spec.rb

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,7 @@ module VCAP::CloudController
2424
service_operations_create_in_progress_cleanup: { frequency_in_seconds: 600 },
2525
service_operations_update_stuck_in_progress_failed: { frequency_in_seconds: 600 },
2626
service_operations_delete_stuck_in_progress_retry: { frequency_in_seconds: 600 },
27+
service_operations_binding_delete_stuck_in_progress_retry: { frequency_in_seconds: 600 },
2728
lifecycle_type_backfill: { frequency_in_seconds: 500 },
2829
service_usage_events: { cutoff_age_in_days: 5 },
2930
completed_tasks: { cutoff_age_in_days: 6 },
@@ -183,6 +184,12 @@ module VCAP::CloudController
183184
expect(block.call).to be_instance_of(Jobs::Runtime::ServiceOperationsDeleteStuckInProgressRetry)
184185
end
185186

187+
expect(clock).to receive(:schedule_frequent_worker_job) do |args, &block|
188+
expect(args).to eql(name: 'service_operations_binding_delete_stuck_in_progress_retry', interval: 600)
189+
expect(Jobs::Runtime::ServiceOperationsBindingDeleteStuckInProgressRetry).to receive(:new).and_call_original
190+
expect(block.call).to be_instance_of(Jobs::Runtime::ServiceOperationsBindingDeleteStuckInProgressRetry)
191+
end
192+
186193
expect(clock).to receive(:schedule_frequent_worker_job) do |args, &block|
187194
expect(args).to eql(name: 'lifecycle_type_backfill', interval: 500)
188195
expect(Jobs::Runtime::LifecycleTypeBackfill).to receive(:new).and_call_original

0 commit comments

Comments
 (0)