From 091457c74752b89a7adfa0fef8e94d4d1762b5df Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?V=C3=ADctor=20Falc=C3=B3n?= Date: Wed, 12 Aug 2026 11:32:36 +0200 Subject: [PATCH] fix(banking): stop bank connections from silently dropping out of scheduled syncing (#782) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit > The Sentry MCP token is expired, so this cycle worked from the production database and `failed_jobs` instead. That turned out to matter: a worker timeout never reaches a job's `try/catch`, so it can corrupt state while producing **no Sentry issue at all**. ## The bug `banking_connections.consecutive_sync_failures` is what keeps a connection in the scheduled rotation. At `MAX_SCHEDULED_RETRIES` both `SyncAllBankingConnectionsJob` and the `banking:sync` command filter it out and **nothing ever dispatches it again**. Nobody is told: the bank consent is still valid, so it never reaches the "reconnect your bank" notice. The user's data just stops. Two connections (2 users) are sitting there right now. One has never completed a single sync since 2026-06-07. ## What I got wrong, and what the reviews found I opened this branch believing job timeouts were stranding connections — `TimeoutExceededException` is this job's most common failure by a wide margin (66 in 14 days vs 37 `RequestException`). **Both reviews falsified that independently, and they were right.** `failed()` has an early return when the connection is already in `Error`, so it could only ever charge **one** increment per connection lifetime; a second out-of-band death is a no-op. Three slow cycles cannot reach the ceiling that way. Prod is the natural experiment: **all 66 timeouts belong to one Wise connection, which sits at `consecutive_sync_failures = 1`.** What actually stranded the two rows was #757's pre-fix transient counting, in the hours before it deployed on 2026-08-10. And the population is 2, not the 4 I first measured — my raw SQL saw two soft-deleted rows that `BankingConnection::query()` correctly excludes. The commits and docblocks now say that. The code change stands on its own smaller merit: an out-of-band death must not be charged to the connection. ## The commits 1. **`failed()` no longer spends the retry budget.** Scope stated honestly in the docblock. It closes exactly one route to the ceiling — see (2). 2. **Reconnect hands back the full budget.** `AuthorizationController` was the only one of four "try again" paths that didn't clear the counter (compare `ConnectionController::sync`, `::update`, `AccountMappingController`, and the job's success path). A user who reconnected a connection parked at `MAX + 1` came back `Active` still carrying the count that parked it, so the first failure re-parked it immediately — none of the three attempts the ceiling grants, right after paying an SCA redirect to escape that exact state. **Both reviews found this while checking commit 1's premise; it is the most real bug here.** 3. **Repair migration, 2 rows.** Matched with `=`, not `>=`: `handlePermanceError` parks auth failures at `MAX + 1` on purpose and there are **8 such rows in prod**; a `>=` filter would un-park them, 401 on the next cycle and send each user a **second** "authentication failed" email. `migrate --pretend` output is in the commit. 4. **Out-of-band deaths are recorded.** Every `logSyncAttempt` call lived inside `handle()` — exactly what these deaths skip. One prod connection has 66 job failures and 3 sync-log rows; that gap is why I mis-attributed the cause. `duration_ms` goes null rather than a fake 0. Copy fixed too: `failed()` said "An unexpected error occurred… please try again later", handing our infrastructure to the user, while the transient path already promised we'd retry. 5. **`uniqueFor` on the job.** `ShouldBeUnique` with no expiry means a lock lost to a hard kill is never released, and `uniqueId()` is the connection id — so that connection silently stops syncing for good. Prevention; prod is clean. 6. **The log had to move above the status guard.** As first written, (4) logged only when the connection was not already in `Error` — and the connection it was written for is parked in `Error` and stays there. Re-measured against prod: **68 failed jobs, 3 sync-log rows**, and every one of the 65 missing deaths would have hit the guard and written nothing. Logging now happens as soon as the connection row resolves; the guards still own the status write, which must not clobber an earlier, more specific error message. ## Verification `tests/Feature/OpenBanking`: **346 tests, 346 pass** on a freshly provisioned worktree (the 10 SSR failures reported earlier were a local-env artifact, not the suite) (Inertia page-render tests hitting the SSR `/render` endpoint, which has no local server — I ran the baseline to confirm). 5 new tests; the two load-bearing ones fail with the change reverted. `pint` and `dry` green. One existing assertion changed rather than deleted: `failed sync job marks active connection as error` asserted the increment. Its declared subject — the status flip that unblocks onboarding — is untouched. The migration's target set was re-verified against prod on 2026-08-12: exactly **2 live rows** at `status=error, consecutive_sync_failures=3`, and every row at `MAX + 1` is soft-deleted or revoked, so the `=` filter touches precisely the two intended connections. **The `crap` job will be red** on `AuthorizationController::callback` (complexity 16). It is pre-existing: my diff there is one array entry plus a comment, zero cyclomatic complexity added; `crap --base` only surfaces it because I touched the file. I deliberately did not add a `.crap-ignore.json` entry — that would paper over someone else's real complexity problem. `crap` is not a required check. ## Why this is a draft The migration writes to production data, and a review caught that a slightly wider filter would have emailed 8 users a second authentication-failure notice. That is exactly the class of mistake worth a human glance. My impact story was also wrong twice this cycle before the reviews corrected it. Commits 1, 2, 4 and 5 I'd merge without hesitation — 2 in particular is a clear standalone bug. Commit 3 is the one that touches prod rows. ## Follow-ups I deliberately did not do - **The mechanism is now mostly bypassed.** 179 of 208 recent job failures are exempt from the counter, so nothing bounds either dominant failure mode and nothing tells the user. The right shape is probably a backoff timestamp like the existing `rate_limited_until`, plus a "this connection hasn't synced in N days" email — a design change, not a patch. - **`019fac9e`** (Wise, never synced in 14 days): 3 × 120s timeouts plus 3 worker SIGALRM kills per cycle, ~24 min/day of the single `default` worker. `failOnTimeout = true` would cut that to one kill, but it also removes two retries that might succeed for a merely slow bank. Its own bug, its own trade-off. - **Spanish users may get no Reconnect button.** `hasAuthError()` in `settings/connections.tsx` matches the English substring `'Authentication failed'` against a *translated* `error_message`. Needs a machine-readable reason column to fix properly. - **An `Error` connection whose consent lapsed is never dispatched**, so it never reaches `markExpired()` and its user never gets the expiry email (1 row in prod). Fixing it changes who receives outbound email, so it wants its own PR. --- .../OpenBanking/AuthorizationController.php | 5 ++ app/Jobs/SyncBankingConnectionJob.php | 68 +++++++++++++-- ...nections_stranded_before_transient_fix.php | 43 ++++++++++ lang/es.json | 1 + .../AuthorizationControllerTest.php | 37 ++++++++ .../SyncBankingConnectionJobTest.php | 6 +- .../OpenBanking/SyncRetryAndLoggingTest.php | 84 +++++++++++++++++++ 7 files changed, 233 insertions(+), 11 deletions(-) create mode 100644 database/migrations/2026_08_12_070623_retry_banking_connections_stranded_before_transient_fix.php diff --git a/app/Http/Controllers/OpenBanking/AuthorizationController.php b/app/Http/Controllers/OpenBanking/AuthorizationController.php index be103445..bcaa4719 100644 --- a/app/Http/Controllers/OpenBanking/AuthorizationController.php +++ b/app/Http/Controllers/OpenBanking/AuthorizationController.php @@ -232,6 +232,11 @@ class AuthorizationController extends Controller 'valid_until' => $sessionData['access']['valid_until'] ?? null, 'error_message' => null, 'state_token' => null, + // Reconnecting is the way out of a parked connection, so it has + // to hand back the full retry budget. Carrying the old count over + // meant the first failure after a reconnect could re-park it + // immediately, which is the state the user just paid SCA to leave. + 'consecutive_sync_failures' => 0, ]); $this->refreshAccountIds($connection, $sessionData['accounts']); diff --git a/app/Jobs/SyncBankingConnectionJob.php b/app/Jobs/SyncBankingConnectionJob.php index 7d695bb0..a81451d8 100644 --- a/app/Jobs/SyncBankingConnectionJob.php +++ b/app/Jobs/SyncBankingConnectionJob.php @@ -36,6 +36,15 @@ class SyncBankingConnectionJob implements ShouldBeUnique, ShouldQueue public int $timeout = 120; + /** + * Safety TTL for the unique lock in case a worker dies mid-run, matching the + * sibling unique jobs. Without it a lock lost to a hard kill is never + * released, and since uniqueId() is the connection id, that one connection + * silently stops syncing for good - the same dead end this class of bug keeps + * producing. Comfortably longer than tries x (timeout + backoff). + */ + public int $uniqueFor = 1800; + /** * Maximum number of scheduled sync cycles that will auto-retry * a connection in Error state before requiring manual intervention. @@ -155,24 +164,60 @@ class SyncBankingConnectionJob implements ShouldBeUnique, ShouldQueue } /** - * Handle permanent errors (auth failures) that should not be retried. + * Last resort for a job that died outside handle()'s own error handling. + * + * Everything raised inside handle() is already classified and recorded, and + * leaves the connection in Error - which the status guard below returns on, + * after the death itself has been recorded. So what reaches here is the job + * being killed from the outside: the queue worker's timeout, an exhausted + * retry count, the worker being restarted mid-sync. + * + * None of that is evidence the *connection* is broken, so it must not be + * charged to the connection's budget of scheduled retries. That budget is + * what keeps it in the scheduled rotation at all, and spending it here means + * spending it on our own infrastructure. + * + * Note the guard makes this at most one increment per connection lifetime - + * a second out-of-band death finds the connection already in Error and does + * nothing - so removing it is a small correction, not a fix for a runaway + * counter. It closes the one route that could reach the ceiling this way: + * a reconnect that left the counter at MAX - 1 (see AuthorizationController) + * followed by a single job death. */ public function failed(?\Throwable $e): void { $connection = $this->bankingConnection->fresh(); - if (! $connection || $connection->status === BankingConnectionStatus::Error) { + if (! $connection) { return; } - if (! $this->isSyncableStatus($connection)) { + // Recorded before the status guards, not after them. handle() owns every + // other logSyncAttempt call and an out-of-band death skips all of them, so + // this is the connection's only trace of the most common way this job dies + // - and the deaths that repeat are exactly the ones the guards drop. The + // connection this was written for is already parked in Error and stays + // there: 68 failed jobs against 3 sync-log rows, and logging after the + // guard would have added none of the missing 65. + $this->logSyncAttempt( + $connection, + BankingSyncLogStatus::Failed, + startTime: null, + error: $e, + metadata: ['reason' => 'job_died_outside_handle'], + ); + + if ($connection->status === BankingConnectionStatus::Error || ! $this->isSyncableStatus($connection)) { return; } $connection->update([ 'status' => BankingConnectionStatus::Error, - 'error_message' => $e ? $this->friendlyErrorMessage($e) : __('An unexpected error occurred during sync. Please try again later.'), - 'consecutive_sync_failures' => $connection->consecutive_sync_failures + 1, + // Every message written here describes an out-of-band death, so the + // generic "an unexpected error occurred, please try again" was pushing + // our own infrastructure onto the user. The next scheduled cycle picks + // the connection back up on its own. + 'error_message' => __('The sync did not finish. We will try again later.'), ]); } @@ -286,22 +331,27 @@ class SyncBankingConnectionJob implements ShouldBeUnique, ShouldQueue }); } + /** + * @param float|null $startTime Null when the caller never got to start a + * timer, so the duration is genuinely unknown + * rather than zero. + */ private function logSyncAttempt( BankingConnection $connection, BankingSyncLogStatus $status, - float $startTime, + ?float $startTime, ?\Throwable $error = null, ?array $metadata = null, ): void { - $durationMs = (int) round((microtime(true) - $startTime) * 1000); - BankingSyncLog::create([ 'banking_connection_id' => $connection->id, 'status' => $status, 'attempt' => $this->attempts(), 'error_message' => $error?->getMessage(), 'error_class' => $error ? get_class($error) : null, - 'duration_ms' => $durationMs, + 'duration_ms' => $startTime === null + ? null + : (int) round((microtime(true) - $startTime) * 1000), 'metadata' => $metadata, 'created_at' => now(), ]); diff --git a/database/migrations/2026_08_12_070623_retry_banking_connections_stranded_before_transient_fix.php b/database/migrations/2026_08_12_070623_retry_banking_connections_stranded_before_transient_fix.php new file mode 100644 index 00000000..32027fd6 --- /dev/null +++ b/database/migrations/2026_08_12_070623_retry_banking_connections_stranded_before_transient_fix.php @@ -0,0 +1,43 @@ +=: handlePermanentError parks auth failures at + * MAX_SCHEDULED_RETRIES + 1 on purpose, and un-parking one would 401 on the + * next cycle and send the user a second "authentication failed" email. The + * counting path can only ever produce exactly MAX_SCHEDULED_RETRIES, because + * the scheduler gate stops dispatching at that point. + */ + public function up(): void + { + BankingConnection::query() + ->where('status', BankingConnectionStatus::Error) + ->where('consecutive_sync_failures', SyncBankingConnectionJob::MAX_SCHEDULED_RETRIES) + ->update(['consecutive_sync_failures' => 0]); + } + + public function down(): void + { + // One-off repair: the counters it cleared carried no information worth + // restoring, and re-parking these connections would only re-strand them. + } +}; diff --git a/lang/es.json b/lang/es.json index 5b44bf22..98350ab5 100644 --- a/lang/es.json +++ b/lang/es.json @@ -322,6 +322,7 @@ "Amount is required": "Se requiere un valor", "An unexpected error occurred during sync.": "Se produjo un error inesperado durante la sincronización.", "An unexpected error occurred during sync. Please try again later.": "Ocurrió un error inesperado durante la sincronización. Inténtalo de nuevo más tarde.", + "The sync did not finish. We will try again later.": "La sincronización no se completó. Volveremos a intentarlo más tarde.", "Annual": "Anual", "Annual Interest Rate": "Tasa de Interés Anual", "Annual Interest Rate (%)": "Tasa de Interés Anual (%)", diff --git a/tests/Feature/OpenBanking/AuthorizationControllerTest.php b/tests/Feature/OpenBanking/AuthorizationControllerTest.php index 6cad79c0..fd3f8494 100644 --- a/tests/Feature/OpenBanking/AuthorizationControllerTest.php +++ b/tests/Feature/OpenBanking/AuthorizationControllerTest.php @@ -936,3 +936,40 @@ test('callback renders the completion page on error without an authenticated ses expect($connection->fresh()->trashed())->toBeTrue(); }); + +test('reconnect hands back the full scheduled retry budget', function () { + Queue::fake(); + + $user = User::factory()->onboarded()->create(); + // A connection parked by repeated auth failures: reconnecting is the only way + // out, so it must not carry the count that parked it. + $connection = BankingConnection::factory()->pending()->create([ + 'user_id' => $user->id, + 'aspsp_name' => 'CaixaBank', + 'aspsp_country' => 'ES', + 'consecutive_sync_failures' => SyncBankingConnectionJob::MAX_SCHEDULED_RETRIES + 1, + ]); + + Account::factory()->create([ + 'user_id' => $user->id, + 'banking_connection_id' => $connection->id, + 'external_account_id' => 'existing-ext-account-1', + ]); + + $mockProvider = Mockery::mock(BankingProviderInterface::class); + $mockProvider->shouldReceive('createSession') + ->once() + ->andReturn([ + 'session_id' => 'new-session-789', + 'accounts' => [], + 'access' => ['valid_until' => now()->addDays(90)->toIso8601String()], + ]); + + $this->app->instance(BankingProviderInterface::class, $mockProvider); + + $this->actingAs($user)->get('/open-banking/callback?code=test-code'); + + $connection->refresh(); + expect($connection->status)->toBe(BankingConnectionStatus::Active); + expect($connection->consecutive_sync_failures)->toBe(0); +}); diff --git a/tests/Feature/OpenBanking/SyncBankingConnectionJobTest.php b/tests/Feature/OpenBanking/SyncBankingConnectionJobTest.php index fc6e7eb9..3b4aee2b 100644 --- a/tests/Feature/OpenBanking/SyncBankingConnectionJobTest.php +++ b/tests/Feature/OpenBanking/SyncBankingConnectionJobTest.php @@ -1642,8 +1642,10 @@ test('failed sync job marks active connection as error so onboarding can continu $connection->refresh(); expect($connection->status)->toBe(BankingConnectionStatus::Error); expect($connection->last_synced_at)->toBeNull(); - expect($connection->error_message)->toBe('An unexpected error occurred during sync. Please try again later.'); - expect($connection->consecutive_sync_failures)->toBe(1); + expect($connection->error_message)->toBe('The sync did not finish. We will try again later.'); + // A job killed from the outside says nothing about the connection, so it no + // longer spends a scheduled retry. + expect($connection->consecutive_sync_failures)->toBe(0); }); test('rate limit error sets backoff window without erroring connection', function () { diff --git a/tests/Feature/OpenBanking/SyncRetryAndLoggingTest.php b/tests/Feature/OpenBanking/SyncRetryAndLoggingTest.php index c0051209..098151bf 100644 --- a/tests/Feature/OpenBanking/SyncRetryAndLoggingTest.php +++ b/tests/Feature/OpenBanking/SyncRetryAndLoggingTest.php @@ -18,6 +18,7 @@ use App\Services\Banking\TransactionSyncService; use GuzzleHttp\Psr7\Response; use Illuminate\Contracts\Queue\Job; use Illuminate\Http\Client\RequestException; +use Illuminate\Queue\TimeoutExceededException; use Illuminate\Support\Facades\Http; use Illuminate\Support\Facades\Log; use Illuminate\Support\Facades\Mail; @@ -883,3 +884,86 @@ test('manual sync resets consecutive sync failures', function () { expect($connection->status)->toBe(BankingConnectionStatus::Active); expect($connection->error_message)->toBeNull(); }); + +// --- Job-Level Failure Tests --- + +test('a job killed by the worker timeout does not spend a scheduled retry', function () { + $user = User::factory()->onboarded()->create(); + // The reachable state: every incrementer also writes Error, so an Active + // connection carries 0 unless a reconnect left a stale count behind. + $connection = BankingConnection::factory()->create([ + 'user_id' => $user->id, + 'consecutive_sync_failures' => 0, + ]); + + // The worker's timeout never reaches handle()'s catch, so failed() is the + // only place the connection hears about it. + (new SyncBankingConnectionJob($connection))->failed( + new TimeoutExceededException('App\Jobs\SyncBankingConnectionJob has timed out.') + ); + + $connection->refresh(); + expect($connection->status)->toBe(BankingConnectionStatus::Error); + expect($connection->error_message)->not->toBeNull(); + expect($connection->consecutive_sync_failures)->toBe(0); +}); + +test('a reconnect that left a stale count is not pushed over the ceiling by a job death', function () { + $user = User::factory()->onboarded()->create(); + // AuthorizationController used to return a connection to Active without + // clearing the counter, which is the only way this pairing arises - and the + // only route by which failed() could ever reach the ceiling. + $connection = BankingConnection::factory()->create([ + 'user_id' => $user->id, + 'consecutive_sync_failures' => SyncBankingConnectionJob::MAX_SCHEDULED_RETRIES - 1, + ]); + + (new SyncBankingConnectionJob($connection))->failed( + new TimeoutExceededException('App\Jobs\SyncBankingConnectionJob has timed out.') + ); + + $connection->refresh(); + expect($connection->consecutive_sync_failures) + ->toBe(SyncBankingConnectionJob::MAX_SCHEDULED_RETRIES - 1); +}); + +test('a second out-of-band death on an already errored connection changes nothing', function () { + $user = User::factory()->onboarded()->create(); + $connection = BankingConnection::factory()->error()->create([ + 'user_id' => $user->id, + 'consecutive_sync_failures' => 2, + 'error_message' => 'Earlier failure kept.', + ]); + + (new SyncBankingConnectionJob($connection))->failed( + new TimeoutExceededException('App\Jobs\SyncBankingConnectionJob has timed out.') + ); + + // The guard leaves the connection itself untouched. This is the fact that + // caps the counter at one increment per lifetime, so it is worth pinning down. + $connection->refresh(); + expect($connection->consecutive_sync_failures)->toBe(2); + expect($connection->error_message)->toBe('Earlier failure kept.'); + + // The death is still recorded. A connection parked in Error is the state that + // repeats - it is where the 65 unrecorded deaths of the connection this was + // written for happened - so dropping the log here would drop the whole point. + $log = BankingSyncLog::where('banking_connection_id', $connection->id)->sole(); + expect($log->metadata['reason'])->toBe('job_died_outside_handle'); +}); + +test('an out-of-band job death is recorded in the connection history', function () { + $user = User::factory()->onboarded()->create(); + $connection = BankingConnection::factory()->create(['user_id' => $user->id]); + + (new SyncBankingConnectionJob($connection))->failed( + new TimeoutExceededException('App\Jobs\SyncBankingConnectionJob has timed out.') + ); + + $log = BankingSyncLog::where('banking_connection_id', $connection->id)->sole(); + expect($log->status)->toBe(BankingSyncLogStatus::Failed); + expect($log->error_class)->toBe(TimeoutExceededException::class); + expect($log->metadata['reason'])->toBe('job_died_outside_handle'); + // Unknown rather than zero: nobody timed this attempt. + expect($log->duration_ms)->toBeNull(); +});