fix(banking): only log sync failures once the connection gives up (#603)
## 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.
This commit is contained in:
parent
bc57eae5c3
commit
8bbff05b26
|
|
@ -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);
|
||||
|
|
|
|||
|
|
@ -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([
|
||||
|
|
|
|||
Loading…
Reference in New Issue