Skip to content

Commit b398497

Browse files
authored
Merge pull request #699 from gideononiru/fix/527-soroban-poll-timeout-pending
fix(escrow): Soroban poll timeout keeps fund() PENDING instead of FAILED (#527)
2 parents 7af2898 + 0d23092 commit b398497

5 files changed

Lines changed: 114 additions & 39 deletions

File tree

‎src/common/idempotency/idempotency.interceptor.ts‎

Lines changed: 8 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -40,14 +40,15 @@ export const IDEMPOTENCY_KEY_TTL_MS = 24 * 60 * 60 * 1000;
4040
*
4141
* Must comfortably outlast the slowest legitimate handler: the escrow
4242
* mutations this interceptor guards go through
43-
* SorobanClientService.invoke → pollTransaction, which polls up to 10
44-
* times at 2000ms (~20s) *on top of* the getAccount/simulate/send RPC
45-
* round-trips. A 30s window was shorter than that worst case, letting a
46-
* client retry reclaim a row whose original request was still actively
47-
* running and re-execute a concurrent money-moving operation (#90). 90s
48-
* leaves ~4x headroom over the poll ceiling for RPC latency.
43+
* SorobanClientService.invoke → pollTransaction, which polls for the
44+
* transaction's full 60s time bound (31 × 2000ms, ~62s, #527) *on top of*
45+
* the getAccount/simulate/send RPC round-trips. A 30s window was shorter
46+
* than that worst case, letting a client retry reclaim a row whose original
47+
* request was still actively running and re-execute a concurrent
48+
* money-moving operation (#90). 180s leaves ~3x headroom over the poll
49+
* ceiling for RPC latency.
4950
*/
50-
export const STALE_PROCESSING_MS = 90 * 1000;
51+
export const STALE_PROCESSING_MS = 180 * 1000;
5152

5253
/** Postgres SQLSTATE for unique_violation. */
5354
const PG_UNIQUE_VIOLATION = '23505';

‎src/escrow/escrow.service.spec.ts‎

Lines changed: 51 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,11 @@ import { getRepositoryToken } from '@nestjs/typeorm';
33
import { BadRequestException } from '@nestjs/common';
44
import { DataSource } from 'typeorm';
55
import { EscrowService } from './escrow.service';
6-
import { SorobanClientService, u64 } from './soroban-client.service';
6+
import {
7+
SorobanClientService,
8+
SorobanPendingError,
9+
u64,
10+
} from './soroban-client.service';
711
import { Escrow, Payment, User } from '../common/entities';
812
import { AssetType, EscrowStatus, PaymentStatus } from '../common/enums';
913
import { TOTAL_BASIS_POINTS } from './split-math.util';
@@ -75,9 +79,7 @@ describe('EscrowService', () => {
7579
entity === Escrow ? escrowRepo.findOne(options) : Promise.resolve(null),
7680
),
7781
find: jest.fn((entity: unknown, options: unknown) =>
78-
entity === Payment
79-
? paymentRepo.find(options)
80-
: Promise.resolve([]),
82+
entity === Payment ? paymentRepo.find(options) : Promise.resolve([]),
8183
),
8284
save: jest.fn((entity: unknown, data: unknown) =>
8385
entity === Payment ? paymentRepo.save(data) : escrowRepo.save(data),
@@ -221,6 +223,29 @@ describe('EscrowService', () => {
221223
);
222224
});
223225

226+
it('keeps the escrow PENDING with the tx hash when the poll times out (#527)', async () => {
227+
soroban.invoke.mockRejectedValueOnce(new SorobanPendingError('tx-abc'));
228+
229+
await expect(
230+
service.fund({
231+
amount: '10',
232+
asset: AssetType.XLM,
233+
funderAddress: 'G...',
234+
bountyId: 'bounty-1',
235+
}),
236+
).rejects.toBeInstanceOf(SorobanPendingError);
237+
238+
const savedCalls = (
239+
escrowRepo.save.mock.calls as [Partial<Escrow>][]
240+
).map((c) => c[0]);
241+
const last = savedCalls[savedCalls.length - 1];
242+
expect(last.status).toBe(EscrowStatus.PENDING);
243+
expect(last.fundTxHash).toBe('tx-abc');
244+
expect(savedCalls.every((e) => e.status !== EscrowStatus.FAILED)).toBe(
245+
true,
246+
);
247+
});
248+
224249
it('keeps the escrow LOCKED when the on-chain call succeeded but the local write failed (#302, #42)', async () => {
225250
// First save (the PENDING row) succeeds; the post-invoke save fails —
226251
// exactly the post-on-chain-success failure #42 describes.
@@ -241,12 +266,12 @@ describe('EscrowService', () => {
241266
const savedCalls = (
242267
escrowRepo.save.mock.calls as [Partial<Escrow>][]
243268
).map((c) => c[0]);
244-
expect(
245-
savedCalls.some((e) => e.status === EscrowStatus.FAILED),
246-
).toBe(false);
247-
expect(
248-
savedCalls.every((e) => e.status !== EscrowStatus.FAILED),
249-
).toBe(true);
269+
expect(savedCalls.some((e) => e.status === EscrowStatus.FAILED)).toBe(
270+
false,
271+
);
272+
expect(savedCalls.every((e) => e.status !== EscrowStatus.FAILED)).toBe(
273+
true,
274+
);
250275

251276
// The retry records the reconciliation marker (and keeps the LOCKED
252277
// status + tx hash) so a reconciliation job can find the row.
@@ -278,9 +303,9 @@ describe('EscrowService', () => {
278303
const savedCalls = (
279304
escrowRepo.save.mock.calls as [Partial<Escrow>][]
280305
).map((c) => c[0]);
281-
expect(
282-
savedCalls.some((e) => e.status === EscrowStatus.FAILED),
283-
).toBe(false);
306+
expect(savedCalls.some((e) => e.status === EscrowStatus.FAILED)).toBe(
307+
false,
308+
);
284309
});
285310

286311
it.each([
@@ -572,15 +597,18 @@ describe('EscrowService', () => {
572597
escrowRepo.findOne.mockResolvedValue({ ...lockedEscrow });
573598
paymentRepo.find.mockResolvedValue([]);
574599
const order: string[] = [];
575-
dataSource.manager.findOne.mockImplementation(
576-
async () => {
577-
order.push('locked-read');
578-
return { ...lockedEscrow };
579-
},
580-
);
600+
dataSource.manager.findOne.mockImplementation(async () => {
601+
order.push('locked-read');
602+
return { ...lockedEscrow };
603+
});
581604
soroban.invoke.mockImplementation(async () => {
582605
order.push('invoke');
583-
return { txHash: 'tx-1', ledger: 1, returnValue: null, status: 'SUCCESS' };
606+
return {
607+
txHash: 'tx-1',
608+
ledger: 1,
609+
returnValue: null,
610+
status: 'SUCCESS',
611+
};
584612
});
585613
paymentRepo.save.mockImplementation(async (data: Partial<Payment>) => {
586614
order.push('payment-write');
@@ -834,7 +862,9 @@ describe('EscrowService', () => {
834862
it('records a failed withdraw via the invokeOnLockedEscrow failure path (#89) and keeps the escrow LOCKED', async () => {
835863
const escrow = lockedPoolEscrow();
836864
escrowRepo.findOne.mockResolvedValue(escrow);
837-
soroban.invoke.mockRejectedValueOnce(new Error('withdraw simulation failed'));
865+
soroban.invoke.mockRejectedValueOnce(
866+
new Error('withdraw simulation failed'),
867+
);
838868

839869
await expect(
840870
service.poolWithdraw('escrow-pool', '10.0000000', 'GRECIPIENT'),

‎src/escrow/escrow.service.ts‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@ import {
1818
ContractInvocationResult,
1919
SorobanClientService,
2020
u64,
21+
SorobanPendingError,
2122
} from './soroban-client.service';
2223
import {
2324
apportionBasisPoints,
@@ -120,6 +121,18 @@ export class EscrowService {
120121
this.contractOpts(escrow),
121122
);
122123
} catch (err) {
124+
if (err instanceof SorobanPendingError) {
125+
// Submitted but not finalized when polling ran out: the funds may
126+
// still lock. Keep PENDING with the hash so reconciliation (#371) or
127+
// a retry resolves it via getTransaction(hash) — marking FAILED here
128+
// invites a client retry that locks funds twice (#527).
129+
escrow.fundTxHash = err.txHash;
130+
escrow.metadata = {
131+
pending: { txHash: err.txHash, at: new Date().toISOString() },
132+
};
133+
await this.escrowRepo.save(escrow);
134+
throw err;
135+
}
123136
// Only reached when the *contract call* failed: nothing was locked
124137
// on-chain, so FAILED is the truthful state.
125138
escrow.status = EscrowStatus.FAILED;

‎src/escrow/soroban-client.service.spec.ts‎

Lines changed: 14 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,12 @@ import { ConfigService } from '@nestjs/config';
22
import { nativeToScVal, rpc } from '@stellar/stellar-sdk';
33
import { AssetType } from '../common/enums';
44
import { AppConfig } from '../config/configuration';
5-
import { SorobanClientService, u64 } from './soroban-client.service';
5+
import {
6+
SOROBAN_TX_TIMEOUT_SECONDS,
7+
SorobanClientService,
8+
SorobanPendingError,
9+
u64,
10+
} from './soroban-client.service';
611

712
jest.mock('@stellar/stellar-sdk', () => ({
813
...jest.requireActual('@stellar/stellar-sdk'),
@@ -240,7 +245,7 @@ describe('SorobanClientService', () => {
240245
expect(result.ledger).toBe(9);
241246
});
242247

243-
it('times out after exhausting all attempts when the transaction stays NOT_FOUND', async () => {
248+
it('polls for the full tx time bound, then throws SorobanPendingError (#527)', async () => {
244249
const getTxSpy = jest
245250
.spyOn(rpc.Server.prototype, 'getTransaction')
246251
.mockResolvedValue(txResponse({ status: 'NOT_FOUND' }));
@@ -249,11 +254,15 @@ describe('SorobanClientService', () => {
249254
() => null,
250255
(err: Error) => err,
251256
);
252-
await jest.advanceTimersByTimeAsync(21_000);
257+
await jest.advanceTimersByTimeAsync(
258+
SOROBAN_TX_TIMEOUT_SECONDS * 1000 + 5_000,
259+
);
253260
const err = await settled;
254261

255-
expect(getTxSpy).toHaveBeenCalledTimes(10);
256-
expect(err).toBeInstanceOf(Error);
262+
// 60s time bound at 2s per poll, plus one final attempt past expiry.
263+
expect(getTxSpy).toHaveBeenCalledTimes(31);
264+
expect(err).toBeInstanceOf(SorobanPendingError);
265+
expect((err as SorobanPendingError).txHash).toBe('mock-hash');
257266
expect((err as Error).message).toContain(
258267
'Timed out waiting for Soroban transaction mock-hash to finalize',
259268
);

‎src/escrow/soroban-client.service.ts‎

Lines changed: 28 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,30 @@ import {
1515
import { AssetType } from '../common/enums';
1616
import { AppConfig } from '../config/configuration';
1717

18+
/** Transaction time bound set on every invocation (`setTimeout`), in seconds. */
19+
export const SOROBAN_TX_TIMEOUT_SECONDS = 60;
20+
const POLL_DELAY_MS = 2000;
21+
/**
22+
* Poll at least as long as the transaction's time bound (+1 attempt), so a
23+
* timeout really means "outcome still unknown at expiry", not "gave up early" (#527).
24+
*/
25+
const POLL_ATTEMPTS =
26+
Math.ceil((SOROBAN_TX_TIMEOUT_SECONDS * 1000) / POLL_DELAY_MS) + 1;
27+
28+
/**
29+
* The transaction was accepted (`sendTransaction` → PENDING) but had not
30+
* finalized when polling ran out. Its outcome is unknown, not failed: it may
31+
* still be included, so callers must not treat this as "nothing happened" (#527).
32+
*/
33+
export class SorobanPendingError extends Error {
34+
constructor(public readonly txHash: string) {
35+
super(
36+
`Timed out waiting for Soroban transaction ${txHash} to finalize; outcome unknown`,
37+
);
38+
this.name = 'SorobanPendingError';
39+
}
40+
}
41+
1842
export interface ContractInvocationResult {
1943
txHash: string;
2044
ledger: number | null;
@@ -185,7 +209,7 @@ export class SorobanClientService {
185209
networkPassphrase: this.networkPassphrase,
186210
})
187211
.addOperation(contract.call(method, ...scArgs))
188-
.setTimeout(60)
212+
.setTimeout(SOROBAN_TX_TIMEOUT_SECONDS)
189213
.build();
190214

191215
const simulated = await this.server.simulateTransaction(tx);
@@ -223,8 +247,8 @@ export class SorobanClientService {
223247

224248
private async pollTransaction(
225249
hash: string,
226-
attempts = 10,
227-
delayMs = 2000,
250+
attempts = POLL_ATTEMPTS,
251+
delayMs = POLL_DELAY_MS,
228252
): Promise<rpc.Api.GetTransactionResponse> {
229253
for (let i = 0; i < attempts; i++) {
230254
const res = await this.server.getTransaction(hash);
@@ -233,9 +257,7 @@ export class SorobanClientService {
233257
}
234258
await new Promise((resolve) => setTimeout(resolve, delayMs));
235259
}
236-
throw new Error(
237-
`Timed out waiting for Soroban transaction ${hash} to finalize`,
238-
);
260+
throw new SorobanPendingError(hash);
239261
}
240262

241263
private toScVal(value: unknown): xdr.ScVal {

0 commit comments

Comments
 (0)