diff --git a/lib/connextclient/ConnextClient.ts b/lib/connextclient/ConnextClient.ts index 6f6ceecf3..24cdb9c14 100644 --- a/lib/connextclient/ConnextClient.ts +++ b/lib/connextclient/ConnextClient.ts @@ -445,6 +445,7 @@ class ConnextClient extends SwapClient { const assetId = this.getTokenAddress(currency); const transferStatusResponse = await this.getHashLockStatus(rHash, assetId); + this.logger.trace(`hashlock status for payment with hash ${rHash} is ${transferStatusResponse.status}`); switch (transferStatusResponse.status) { case 'PENDING': return { state: PaymentState.Pending }; diff --git a/lib/swaps/SwapRecovery.ts b/lib/swaps/SwapRecovery.ts index 090618c4b..3759f6a35 100644 --- a/lib/swaps/SwapRecovery.ts +++ b/lib/swaps/SwapRecovery.ts @@ -16,11 +16,12 @@ interface SwapRecovery { * ensuring that we do not lose funds on a partially completed swap. */ class SwapRecovery extends EventEmitter { + public static readonly PENDING_SWAP_RECHECK_INTERVAL = 300000; + /** A map of payment hashes to swaps where we have a pending outgoing payment but don't know the preimage. */ private pendingSwaps: Map = new Map(); private pendingSwapsTimer?: NodeJS.Timeout; /** The time in milliseconds between checks on the status of pending swaps. */ - private static readonly PENDING_SWAP_RECHECK_INTERVAL = 300000; constructor(private swapClientManager: SwapClientManager, private logger: Logger) { super(); diff --git a/lib/swaps/Swaps.ts b/lib/swaps/Swaps.ts index 318e552f9..2be2e5280 100644 --- a/lib/swaps/Swaps.ts +++ b/lib/swaps/Swaps.ts @@ -731,16 +731,36 @@ class Swaps extends EventEmitter { try { await swapClient.settleInvoice(rHash, rPreimage, currency); } catch (err) { - // if we couldn't settle the invoice then we fail the deal which throws - // it into recovery where we will try to settle our payment again this.logger.error(`could not settle invoice for deal ${rHash}`, err); - this.logger.alert(`incoming ${currency} payment with hash ${rHash} could not be settled with preimage ${rPreimage}, this is not expected and funds may be at risk`); - await this.failDeal({ - deal, - failureReason: SwapFailureReason.UnexpectedClientError, - errorMessage: err.message, - }); - return; + if (deal.role === SwapRole.Maker) { + // if we are the maker, we must be able to settle the invoice otherwise we lose funds + // we will continuously retry settling the invoice until it succeeds + // TODO: determine when we are permanently unable (due to htlc expiration or unknown invoice hash) to + // settle an invoice and fail the deal, rather than endlessly retrying settle invoice calls + this.logger.alert(`incoming ${currency} payment with hash ${rHash} could not be settled with preimage ${rPreimage}, this is not expected and funds may be at risk`); + + const settleRetryPromise = new Promise((resolve) => { + const settleRetryTimer = setInterval(async () => { + try { + await swapClient.settleInvoice(rHash, rPreimage, currency); + this.logger.info(`successfully settled invoice for deal ${rHash} on retry`); + resolve(); + clearInterval(settleRetryTimer); + } catch (err) { + this.logger.error(`could not settle invoice for deal ${rHash}`, err); + } + }, SwapRecovery.PENDING_SWAP_RECHECK_INTERVAL); + }); + await settleRetryPromise; + } else { + // if we are the taker, funds are not at risk and we may simply fail the deal + await this.failDeal({ + deal, + failureReason: SwapFailureReason.UnexpectedClientError, + errorMessage: err.message, + }); + return; + } } // if we succeeded in settling our incoming payment we update the deal phase & state @@ -1033,15 +1053,25 @@ class Swaps extends EventEmitter { try { deal.rPreimage = await swapClient.sendPayment(deal); } catch (err) { - this.logger.debug(`sendPayment in resolveHash failed due to ${err.message}`); + this.logger.debug(`sendPayment in resolveHash for swap ${deal.rHash} failed due to ${err.message}`); - const failDeal = async (paymentState: PaymentState) => { + // the send payment call failed but we first double check its final status, so + // we only fail the deal when we know our payment won't go through. otherwise + // we extract the preimage if the payment went through in spite of the error + // or we fail the deal and go to SwapRecovery if it's still pending + const paymentStatus = await swapClient.lookupPayment(rHash, deal.takerCurrency, deal.destination); + if (paymentStatus.state === PaymentState.Succeeded && paymentStatus.preimage) { + // just kidding, turns out the payment actually went through and we have the preimage! + // so we can continue with the swap + this.logger.debug(`payment for swap ${deal.rHash} succeeded despite sendPayment error, preimage is ${paymentStatus.preimage}`); + deal.rPreimage = paymentStatus.preimage; + } else if (paymentStatus.state === PaymentState.Failed) { + // we've confirmed the payment has failed for good, so we can fail the deal switch (err.code) { case errorCodes.FINAL_PAYMENT_ERROR: await this.failDeal({ deal, peer, - paymentState, failedCurrency: deal.takerCurrency, failureReason: SwapFailureReason.SendPaymentFailure, errorMessage: err.message, @@ -1050,7 +1080,6 @@ class Swaps extends EventEmitter { case errorCodes.PAYMENT_REJECTED: await this.failDeal({ deal, - paymentState, failureReason: SwapFailureReason.PaymentRejected, errorMessage: err.message, }); @@ -1059,25 +1088,43 @@ class Swaps extends EventEmitter { await this.failDeal({ deal, peer, - paymentState, failedCurrency: deal.takerCurrency, failureReason: SwapFailureReason.UnknownError, errorMessage: err.message, }); break; } - }; - - // the payment failed but we first double check its final status, so we - // only fail the deal when we know our payment won't go through. otherwise - // we extract the preimage if the payment went through in spite of the error - // or we fail the deal and go to SwapRecovery if it's still pending - const paymentStatus = await swapClient.lookupPayment(rHash, deal.takerCurrency, deal.destination); - if (paymentStatus.state === PaymentState.Succeeded) { - deal.rPreimage = paymentStatus.preimage!; - } else { - await failDeal(paymentStatus.state); throw err; + } else { + // the payment is in limbo, and could eventually go through. we need to make + // sure that the taker doesn't claim our payment without us having a chance + // to claim ours. we will monitor the outcome here. + this.logger.info(`started monitoring pending payment for swap ${deal.rHash}, will check every ${SwapRecovery.PENDING_SWAP_RECHECK_INTERVAL / 1000} seconds`); + const pendingPaymentPromise = new Promise((resolve, reject) => { + const recheckTimer = setInterval(async () => { + this.logger.trace(`checking pending payment status for swap ${deal.rHash}`); + const paymentStatus = await swapClient.lookupPayment(rHash, deal.takerCurrency, deal.destination); + this.logger.trace(`payment for swap ${deal.rHash} is in ${PaymentState[paymentStatus.state]} status}`); + if (paymentStatus.state === PaymentState.Succeeded && paymentStatus.preimage) { + // the payment went through, we resolve the promise to the resolved preimage + resolve(paymentStatus.preimage); + clearInterval(recheckTimer); + } else if (paymentStatus.state === PaymentState.Failed) { + // the payment finally failed, so we can fail the deal + await this.failDeal({ + deal, + peer, + failedCurrency: deal.takerCurrency, + failureReason: SwapFailureReason.SendPaymentFailure, + errorMessage: err.message, + }); + reject(err); + clearInterval(recheckTimer); + } + }, SwapRecovery.PENDING_SWAP_RECHECK_INTERVAL); + }); + + deal.rPreimage = await pendingPaymentPromise; } } @@ -1166,7 +1213,7 @@ class Swaps extends EventEmitter { /** * Fails a deal and optionally sends a SwapFailurePacket to a peer, if provided. */ - private failDeal = async ({ deal, failureReason, failedCurrency, errorMessage, peer, reqId, paymentState }: + private failDeal = async ({ deal, failureReason, failedCurrency, errorMessage, peer, reqId }: { deal: SwapDeal, failureReason: SwapFailureReason, @@ -1178,13 +1225,9 @@ class Swaps extends EventEmitter { peer?: Peer, /** An optional reqId in case the SwapFailedPacket is in response to a swap request. */ reqId?: string, - /** The state of the outgoing payment involved with this swap. */ - paymentState?: PaymentState, }) => { assert(deal.state !== SwapState.Completed, 'Can not fail a completed deal.'); - this.logger.trace(`failing deal ${deal.rHash} in state ${SwapState[deal.state]} & phase ${SwapPhase[deal.phase]} due to ${SwapFailureReason[failureReason]}`); - // If we are already in error state and got another error report we // aggregate all error reasons by concatenation if (deal.state === SwapState.Error) { @@ -1194,11 +1237,11 @@ class Swaps extends EventEmitter { deal.errorMessage += ` (${failedCurrency})`; } } - this.logger.debug(`new deal error message for ${deal.rHash}: + ${deal.errorMessage}`); + this.logger.trace(`new deal error message for ${deal.rHash}: + ${deal.errorMessage}`); return; } - let logMessage = `deal ${deal.rHash} failed due to ${SwapFailureReason[failureReason]}`; + let logMessage = `deal ${deal.rHash} failed in state ${SwapState[deal.state]} & phase ${SwapPhase[deal.phase]} due to ${SwapFailureReason[failureReason]}`; if (failedCurrency) { logMessage += ` (${failedCurrency})`; } @@ -1251,20 +1294,14 @@ class Swaps extends EventEmitter { clearTimeout(this.timeouts.get(deal.rHash)); this.timeouts.delete(deal.rHash); + if (deal.role === SwapRole.Maker) { - if (deal.phase === SwapPhase.SwapAccepted) { - // if we are the maker and we have accepted a swap deal but we haven't yet started paying the taker - // then we should cancel the invoice for our incoming payment if one exists + // if we are the maker and we have accepted a swap deal or were sending a payment that + // has since failed then we should cancel the invoice for our incoming payment this + // will cancel any incoming HTLCs rather than letting them expire and force close channels + if (deal.phase === SwapPhase.SwapAccepted || deal.phase === SwapPhase.SendingPayment) { const swapClient = this.swapClientManager.get(deal.makerCurrency)!; swapClient.removeInvoice(deal.rHash).catch(this.logger.error); // we don't need to await the remove invoice call - } else if ((paymentState === undefined || paymentState === PaymentState.Pending) && - (deal.phase === SwapPhase.SendingPayment || deal.phase === SwapPhase.PreimageResolved)) { - // if the swap fails while we are in the middle of sending payment as the maker - // and we haven't confirmed that our outgoing payment is no longer pending - // we need to make sure that the taker doesn't claim our payment without us having a chance - // to claim ours. we will send this swap to recovery to monitor its outcome - const swapDealInstance = await this.repository.getSwapDeal(deal.rHash); - await this.swapRecovery.recoverDeal(swapDealInstance!); } } else if (deal.phase === SwapPhase.SendingPayment) { const swapClient = this.swapClientManager.get(deal.takerCurrency)!; diff --git a/test/simulation/custom-xud.patch b/test/simulation/custom-xud.patch index 94d7a68a8..3eb871903 100644 --- a/test/simulation/custom-xud.patch +++ b/test/simulation/custom-xud.patch @@ -1,11 +1,11 @@ diff --git a/lib/Xud.ts b/lib/Xud.ts -index 08402caa..c9972d25 100644 +index 52ed8b5b4..93c5029b3 100644 --- a/lib/Xud.ts +++ b/lib/Xud.ts @@ -87,6 +87,11 @@ class Xud extends EventEmitter { this.logger.info('config file loaded'); } - + + this.logger.info('CUSTOM-XUD'); + if (process.env.CUSTOM_SCENARIO) { + this.logger.info(`CUSTOM_SCENARIO=${process.env.CUSTOM_SCENARIO}`); @@ -15,18 +15,15 @@ index 08402caa..c9972d25 100644 if (!this.config.rpc.disable) { // start rpc server first, it will respond with UNAVAILABLE error diff --git a/lib/swaps/SwapRecovery.ts b/lib/swaps/SwapRecovery.ts -index 090618c4..820f8909 100644 +index 3759f6a35..4089dc944 100644 --- a/lib/swaps/SwapRecovery.ts +++ b/lib/swaps/SwapRecovery.ts -@@ -28,7 +28,21 @@ class SwapRecovery extends EventEmitter { - +@@ -29,7 +29,18 @@ class SwapRecovery extends EventEmitter { + public beginTimer = () => { if (!this.pendingSwapsTimer) { - this.pendingSwapsTimer = setInterval(this.checkPendingSwaps, SwapRecovery.PENDING_SWAP_RECHECK_INTERVAL); + let interval = SwapRecovery.PENDING_SWAP_RECHECK_INTERVAL; -+ if (process.env.CUSTOM_SCENARIO === 'INSTABILITY::MAKER_CLIENT_CRASHED_BEFORE_SETTLE') { -+ interval = 2000; -+ } + if (process.env.CUSTOM_SCENARIO === 'INSTABILITY::MAKER_CRASH_WHILE_SENDING') { + interval = 2000; + } @@ -40,12 +37,12 @@ index 090618c4..820f8909 100644 + this.pendingSwapsTimer = setInterval(this.checkPendingSwaps, interval); } } - + diff --git a/lib/swaps/Swaps.ts b/lib/swaps/Swaps.ts -index 908f4cc3..b72ab4dc 100644 +index 3a2367f52..ec1712119 100644 --- a/lib/swaps/Swaps.ts +++ b/lib/swaps/Swaps.ts -@@ -721,6 +721,24 @@ class Swaps extends EventEmitter { +@@ -729,6 +729,24 @@ class Swaps extends EventEmitter { // if the swap has already been failed, then we leave the swap recovery module // to attempt to settle the invoice and claim funds rather than do it here try { @@ -69,8 +66,19 @@ index 908f4cc3..b72ab4dc 100644 + this.logger.info('SETTLING INVOICE'); await swapClient.settleInvoice(rHash, rPreimage, currency); } catch (err) { - // if we couldn't settle the invoice then we fail the deal which throws -@@ -745,6 +763,16 @@ class Swaps extends EventEmitter { + this.logger.error(`could not settle invoice for deal ${rHash}`, err); +@@ -749,7 +767,9 @@ class Swaps extends EventEmitter { + } catch (err) { + this.logger.error(`could not settle invoice for deal ${rHash}`, err); + } +- }, SwapRecovery.PENDING_SWAP_RECHECK_INTERVAL); ++ }, process.env.CUSTOM_SCENARIO === 'INSTABILITY::MAKER_CLIENT_CRASHED_BEFORE_SETTLE' ? ++ 2000 : ++ SwapRecovery.PENDING_SWAP_RECHECK_INTERVAL); + }); + await settleRetryPromise; + } else { +@@ -773,6 +793,16 @@ class Swaps extends EventEmitter { * accepted, initiates the swap. */ private handleSwapAccepted = async (responsePacket: packets.SwapAcceptedPacket, peer: Peer) => { @@ -87,8 +95,8 @@ index 908f4cc3..b72ab4dc 100644 assert(responsePacket.body, 'SwapAcceptedPacket does not contain a body'); const { quantity, rHash, makerCltvDelta } = responsePacket.body; const deal = this.getDeal(rHash); -@@ -832,6 +860,11 @@ class Swaps extends EventEmitter { - +@@ -860,6 +890,11 @@ class Swaps extends EventEmitter { + try { await makerSwapClient.sendPayment(deal); + @@ -99,10 +107,10 @@ index 908f4cc3..b72ab4dc 100644 } catch (err) { // first we must handle the edge case where the maker has paid us but failed to claim our payment // in this case, we've already marked the swap as having been paid and completed -@@ -1013,6 +1046,18 @@ class Swaps extends EventEmitter { - +@@ -1041,6 +1076,18 @@ class Swaps extends EventEmitter { + this.logger.debug('Executing maker code to resolve hash'); - + + if (process.env.CUSTOM_SCENARIO === 'SECURITY::MAKER_1ST_HTLC_STALL') { + this.logger.info(`CUSTOM_SCENARIO: ${process.env.CUSTOM_SCENARIO}`); + const makerSwapClient = this.swapClientManager.get(deal.makerCurrency)!; @@ -116,11 +124,11 @@ index 908f4cc3..b72ab4dc 100644 + } + const swapClient = this.swapClientManager.get(deal.takerCurrency)!; - + // we update the phase persist the deal to the database before we attempt to send payment -@@ -1023,6 +1068,13 @@ class Swaps extends EventEmitter { +@@ -1051,6 +1098,13 @@ class Swaps extends EventEmitter { assert(deal.state !== SwapState.Error, `cannot send payment for failed swap ${deal.rHash}`); - + try { + if (process.env.CUSTOM_SCENARIO === 'INSTABILITY::MAKER_CRASH_WHILE_SENDING') { + setTimeout(() => { @@ -131,11 +139,11 @@ index 908f4cc3..b72ab4dc 100644 + deal.rPreimage = await swapClient.sendPayment(deal); } catch (err) { - this.logger.debug(`sendPayment in resolveHash failed due to ${err.message}`); -@@ -1073,10 +1125,21 @@ class Swaps extends EventEmitter { + this.logger.debug(`sendPayment in resolveHash for swap ${deal.rHash} failed due to ${err.message}`); +@@ -1128,10 +1182,21 @@ class Swaps extends EventEmitter { } } - + + if (process.env.CUSTOM_SCENARIO === 'INSTABILITY::MAKER_CRASH_AFTER_SEND_BEFORE_PREIMAGE_RESOLVED') { + this.logger.info(`CUSTOM_SCENARIO: ${process.env.CUSTOM_SCENARIO}`); + process.exit(); @@ -155,10 +163,10 @@ index 908f4cc3..b72ab4dc 100644 return deal.rPreimage; } else { // If we are here we are the taker -@@ -1084,6 +1147,16 @@ class Swaps extends EventEmitter { +@@ -1139,6 +1204,16 @@ class Swaps extends EventEmitter { assert(htlcCurrency === undefined || htlcCurrency === deal.takerCurrency, 'incoming htlc does not match expected deal currency'); this.logger.debug('Executing taker code to resolve hash'); - + + if (process.env.CUSTOM_SCENARIO === 'SECURITY::TAKER_2ND_HTLC_STALL') { + this.logger.info(`CUSTOM_SCENARIO: ${process.env.CUSTOM_SCENARIO}`); + return ''; @@ -172,8 +180,8 @@ index 908f4cc3..b72ab4dc 100644 return deal.rPreimage; } } -@@ -1259,8 +1332,11 @@ class Swaps extends EventEmitter { - await this.swapRecovery.recoverDeal(swapDealInstance!); +@@ -1302,8 +1377,11 @@ class Swaps extends EventEmitter { + swapClient.removeInvoice(deal.rHash).catch(this.logger.error); // we don't need to await the remove invoice call } } else if (deal.phase === SwapPhase.SendingPayment) { - const swapClient = this.swapClientManager.get(deal.takerCurrency)!; @@ -184,10 +192,10 @@ index 908f4cc3..b72ab4dc 100644 + swapClient.removeInvoice(deal.rHash).catch(this.logger.error); // we don't need to await the remove invoice call + } } - + this.logger.trace(`emitting swap.failed event for ${deal.rHash}`); -@@ -1324,9 +1400,14 @@ class Swaps extends EventEmitter { - +@@ -1367,9 +1445,14 @@ class Swaps extends EventEmitter { + if (deal.role === SwapRole.Maker) { // the maker begins execution of the swap upon accepting the deal +