From 8bbff05b2693cef3edbc8fc4c9350f6ba7ab99d6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?V=C3=ADctor=20Falc=C3=B3n?= Date: Sat, 27 Jun 2026 18:04:36 +0200 Subject: [PATCH] fix(banking): only log sync failures once the connection gives up (#603) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Why Production log dashboards were flooded with paired `Banking sync failed` + `EnableBanking API error` warnings for a handful of users, recurring on every 6-hour `banking:sync` cycle for days. Investigation (prod `BankingSyncLog` + connection state) showed the affected connections are **healthy and syncing daily** (`last_synced_at` = today, `consecutive_sync_failures = 0`): the first attempt hits a transient `ASPSP_ERROR` / `429`, and the job's retry recovers it. So the warnings are **noise, not breakage** — but `SyncBankingConnectionJob` logged `Banking sync failed` inside the catch block on *every* attempt, including non-final ones that later succeed. That's one warning per cycle for connections that sync fine, which reads as a failure and causes alert fatigue. ## What Gate the `Log::log(...)` call so it only fires when the connection actually gives up: - the **final attempt** (`attempts() >= tries`), or - a **permanent auth error** (`isAuthError`). Transient errors recovered by the retry are no longer logged. Per-attempt traceability is unchanged: `BankingSyncLog` still records every attempt (Success / Failed) in the database. ## Tests `tests/Feature/OpenBanking/SyncRetryAndLoggingTest.php`: - non-final attempt → `Log::log` is **not** called - final attempt → `Log::log('error', 'Banking sync failed', ...)` **is** called once Full file: 24/24 passing. --- app/Jobs/SyncBankingConnectionJob.php | 7 +- .../OpenBanking/SyncRetryAndLoggingTest.php | 81 +++++++++++++++++++ 2 files changed, 87 insertions(+), 1 deletion(-) diff --git a/app/Jobs/SyncBankingConnectionJob.php b/app/Jobs/SyncBankingConnectionJob.php index f6b7ed18..6378c545 100644 --- a/app/Jobs/SyncBankingConnectionJob.php +++ b/app/Jobs/SyncBankingConnectionJob.php @@ -128,7 +128,12 @@ class SyncBankingConnectionJob implements ShouldBeUnique, ShouldQueue $context['provider_code'] = $e->providerCode; } - Log::log($e instanceof TransientBankingProviderException ? 'warning' : 'error', 'Banking sync failed', $context); + // Only report once the connection actually gives up. Transient errors on a + // non-final attempt are recovered by the retry and would otherwise spam one + // warning per scheduled cycle for connections that ultimately sync fine. + if ($this->attempts() >= $this->tries || $this->isAuthError($e)) { + Log::log($e instanceof TransientBankingProviderException ? 'warning' : 'error', 'Banking sync failed', $context); + } if ($this->isRateLimitError($e)) { $this->applyRateLimitBackoff($connection, $e); diff --git a/tests/Feature/OpenBanking/SyncRetryAndLoggingTest.php b/tests/Feature/OpenBanking/SyncRetryAndLoggingTest.php index 9bdd9991..22c28fc0 100644 --- a/tests/Feature/OpenBanking/SyncRetryAndLoggingTest.php +++ b/tests/Feature/OpenBanking/SyncRetryAndLoggingTest.php @@ -18,6 +18,7 @@ use GuzzleHttp\Psr7\Response; use Illuminate\Contracts\Queue\Job; use Illuminate\Http\Client\RequestException; use Illuminate\Support\Facades\Http; +use Illuminate\Support\Facades\Log; use Illuminate\Support\Facades\Mail; use Illuminate\Support\Facades\Queue; @@ -109,6 +110,86 @@ test('temporary error on final attempt sets error status and increments consecut expect($connection->consecutive_sync_failures)->toBe(1); }); +test('temporary error on non-final attempt is not logged', function () { + $user = User::factory()->onboarded()->create(); + $connection = BankingConnection::factory()->create([ + 'user_id' => $user->id, + 'last_synced_at' => now()->subDay(), + ]); + Account::factory()->connected()->create([ + 'user_id' => $user->id, + 'banking_connection_id' => $connection->id, + 'external_account_id' => 'ext-123', + ]); + + $transactionSync = Mockery::mock(TransactionSyncService::class); + $transactionSync->shouldReceive('sync')->andThrow( + new RequestException( + new Illuminate\Http\Client\Response(new Response(500)) + ) + ); + + $balanceSync = Mockery::mock(BalanceSyncService::class); + + Log::spy(); + + // Attempt 1 of 3: the retry will recover, so nothing should be reported yet. + $job = new SyncBankingConnectionJob($connection); + $job->job = Mockery::mock(Job::class); + $job->job->shouldReceive('attempts')->andReturn(1); + $job->job->shouldReceive('isReleased')->andReturn(false); + $job->job->shouldReceive('isDeletedOrReleased')->andReturn(false); + $job->job->shouldReceive('hasFailed')->andReturn(false); + + try { + runSync($job, $transactionSync, $balanceSync); + } catch (RequestException) { + // Expected: rethrown so the queue retries it. + } + + Log::shouldNotHaveReceived('log'); +}); + +test('temporary error on final attempt is logged', function () { + $user = User::factory()->onboarded()->create(); + $connection = BankingConnection::factory()->create([ + 'user_id' => $user->id, + 'last_synced_at' => now()->subDay(), + ]); + Account::factory()->connected()->create([ + 'user_id' => $user->id, + 'banking_connection_id' => $connection->id, + 'external_account_id' => 'ext-123', + ]); + + $transactionSync = Mockery::mock(TransactionSyncService::class); + $transactionSync->shouldReceive('sync')->andThrow( + new RequestException( + new Illuminate\Http\Client\Response(new Response(500)) + ) + ); + + $balanceSync = Mockery::mock(BalanceSyncService::class); + + Log::spy(); + + // Final attempt (3 of 3): the connection gives up, so it must be reported. + $job = new SyncBankingConnectionJob($connection); + $job->job = Mockery::mock(Job::class); + $job->job->shouldReceive('attempts')->andReturn(3); + $job->job->shouldReceive('isReleased')->andReturn(false); + $job->job->shouldReceive('isDeletedOrReleased')->andReturn(false); + $job->job->shouldReceive('hasFailed')->andReturn(false); + + try { + runSync($job, $transactionSync, $balanceSync); + } catch (RequestException) { + // Expected + } + + Log::shouldHaveReceived('log')->with('error', 'Banking sync failed', Mockery::any())->once(); +}); + test('transient banking provider error on final attempt uses retry later message', function () { $user = User::factory()->onboarded()->create(); $connection = BankingConnection::factory()->create([