From 307d2d7a98e55d2abe71d0147a066f39afa6bc58 Mon Sep 17 00:00:00 2001 From: callebtc <93376500+callebtc@users.noreply.github.com> Date: Sun, 6 Oct 2024 17:51:54 +0200 Subject: [PATCH] Halt melt on exception (#635) * halt melt for payment status exception * refactor * less log * add fakewallet test throwing exceptions --- cashu/core/settings.py | 2 + cashu/lightning/fake.py | 5 + cashu/mint/ledger.py | 217 ++++++++++++++++++++-------------------- tests/test_mint_melt.py | 36 +++++++ 4 files changed, 153 insertions(+), 107 deletions(-) diff --git a/cashu/core/settings.py b/cashu/core/settings.py index ab18910..8f305a2 100644 --- a/cashu/core/settings.py +++ b/cashu/core/settings.py @@ -140,7 +140,9 @@ class FakeWalletSettings(MintSettings): fakewallet_delay_incoming_payment: Optional[float] = Field(default=3.0) fakewallet_stochastic_invoice: bool = Field(default=False) fakewallet_payment_state: Optional[str] = Field(default="SETTLED") + fakewallet_payment_state_exception: Optional[bool] = Field(default=False) fakewallet_pay_invoice_state: Optional[str] = Field(default="SETTLED") + fakewallet_pay_invoice_state_exception: Optional[bool] = Field(default=False) class MintInformation(CashuSettings): diff --git a/cashu/lightning/fake.py b/cashu/lightning/fake.py index 7e8c6ac..59073fd 100644 --- a/cashu/lightning/fake.py +++ b/cashu/lightning/fake.py @@ -147,6 +147,9 @@ class FakeWallet(LightningBackend): ) async def pay_invoice(self, quote: MeltQuote, fee_limit: int) -> PaymentResponse: + if settings.fakewallet_pay_invoice_state_exception: + raise Exception("FakeWallet pay_invoice exception") + invoice = decode(quote.request) if settings.fakewallet_delay_outgoing_payment: @@ -189,6 +192,8 @@ class FakeWallet(LightningBackend): ) async def get_payment_status(self, checking_id: str) -> PaymentStatus: + if settings.fakewallet_payment_state_exception: + raise Exception("FakeWallet get_payment_status exception") if settings.fakewallet_payment_state: return PaymentStatus( result=PaymentResult[settings.fakewallet_payment_state] diff --git a/cashu/mint/ledger.py b/cashu/mint/ledger.py index f8b46ad..c08531e 100644 --- a/cashu/mint/ledger.py +++ b/cashu/mint/ledger.py @@ -68,11 +68,11 @@ from .verification import LedgerVerification class Ledger(LedgerVerification, LedgerSpendingConditions, LedgerTasks, LedgerFeatures): backends: Mapping[Method, Mapping[Unit, LightningBackend]] = {} - locks: Dict[str, asyncio.Lock] = {} # holds multiprocessing locks keysets: Dict[str, MintKeyset] = {} events = LedgerEventManager() db_read: DbReadHelper invoice_listener_tasks: List[asyncio.Task] = [] + disable_melt: bool = False def __init__( self, @@ -130,8 +130,7 @@ class Ledger(LedgerVerification, LedgerSpendingConditions, LedgerTasks, LedgerFe logger.error( "The backend for" f" {self.backends[method][unit].__class__.__name__} isn't" - f" working properly: '{status.error_message}'", - RuntimeWarning, + f" working properly: '{status.error_message}'" ) exit(1) logger.info(f"Backend balance: {status.balance} {unit.name}") @@ -880,6 +879,10 @@ class Ledger(LedgerVerification, LedgerSpendingConditions, LedgerTasks, LedgerFe Returns: Tuple[str, List[BlindedMessage]]: Proof of payment and signed outputs for returning overpaid fees to wallet. """ + # make sure we're allowed to melt + if self.disable_melt: + raise NotAllowedError("Melt is disabled. Please contact the operator.") + # get melt quote and check if it was already paid melt_quote = await self.get_melt_quote(quote_id=quote) if not melt_quote.unpaid: @@ -913,16 +916,14 @@ class Ledger(LedgerVerification, LedgerSpendingConditions, LedgerTasks, LedgerFe raise TransactionError( f"not enough fee reserve provided for melt. Provided fee reserve: {fee_reserve_provided}, needed: {melt_quote.fee_reserve}" ) - # verify that the amount of the proofs is not larger than the maximum allowed if settings.mint_max_peg_out and total_provided > settings.mint_max_peg_out: raise NotAllowedError( f"Maximum melt amount is {settings.mint_max_peg_out} sat." ) - # verify inputs and their spending conditions # note, we do not verify outputs here, as they are only used for returning overpaid fees - # we should have used _verify_outputs here already (see above) + # We must have called _verify_outputs here already! (see above) await self.verify_inputs_and_outputs(proofs=proofs) # set proofs to pending to avoid race conditions @@ -931,114 +932,116 @@ class Ledger(LedgerVerification, LedgerSpendingConditions, LedgerTasks, LedgerFe ) previous_state = melt_quote.state melt_quote = await self.db_write._set_melt_quote_pending(melt_quote) - try: - # if the melt corresponds to an internal mint, mark both as paid - melt_quote = await self.melt_mint_settle_internally(melt_quote, proofs) - # quote not paid yet (not internal), pay it with the backend - if not melt_quote.paid: - logger.debug(f"Lightning: pay invoice {melt_quote.request}") - try: - payment = await self.backends[method][unit].pay_invoice( - melt_quote, melt_quote.fee_reserve * 1000 + + # if the melt corresponds to an internal mint, mark both as paid + melt_quote = await self.melt_mint_settle_internally(melt_quote, proofs) + # quote not paid yet (not internal), pay it with the backend + if not melt_quote.paid: + logger.debug(f"Lightning: pay invoice {melt_quote.request}") + try: + payment = await self.backends[method][unit].pay_invoice( + melt_quote, melt_quote.fee_reserve * 1000 + ) + logger.debug( + f"Melt – Result: {payment.result.name}: preimage: {payment.preimage}," + f" fee: {payment.fee.str() if payment.fee is not None else 'None'}" + ) + if ( + payment.checking_id + and payment.checking_id != melt_quote.checking_id + ): + logger.warning( + f"pay_invoice returned different checking_id: {payment.checking_id} than melt quote: {melt_quote.checking_id}. Will use it for potentially checking payment status later." ) - logger.debug( - f"Melt – Result: {payment.result}: preimage: {payment.preimage}," - f" fee: {payment.fee.str() if payment.fee is not None else 'None'}" - ) - if ( - payment.checking_id - and payment.checking_id != melt_quote.checking_id - ): - logger.warning( - f"pay_invoice returned different checking_id: {payment.checking_id} than melt quote: {melt_quote.checking_id}. Will use it for potentially checking payment status later." - ) - melt_quote.checking_id = payment.checking_id - await self.crud.update_melt_quote(quote=melt_quote, db=self.db) - - except Exception as e: - logger.error(f"Exception during pay_invoice: {e}") - payment = PaymentResponse( - result=PaymentResult.UNKNOWN, - error_message=str(e), - ) - - match payment.result: - case PaymentResult.FAILED | PaymentResult.UNKNOWN: - # explicitly check payment status for failed or unknown payment states - checking_id = payment.checking_id or melt_quote.checking_id - logger.debug( - f"Payment state is {payment.result}. Checking status for {checking_id}" - ) - try: - status = await self.backends[method][ - unit - ].get_payment_status(checking_id) - except Exception as e: - # Something went wrong, better to keep the proofs in pending state - logger.error( - f"Lightning backend error: could not check payment status. Proofs for melt quote {melt_quote.quote} are stuck as PENDING. Error: {e}" - ) - return PostMeltQuoteResponse.from_melt_quote(melt_quote) - - match status.result: - case PaymentResult.FAILED | PaymentResult.UNKNOWN: - # NOTE: We only throw a payment error if the payment AND a subsequent status check failed - raise LightningError( - f"Lightning payment failed: {payment.error_message}. Error: {status.error_message}" - ) - case _: - logger.error( - f"Payment state is {status.result} and payment was {payment.result}. Proofs for melt quote {melt_quote.quote} are stuck as PENDING." - ) - return PostMeltQuoteResponse.from_melt_quote(melt_quote) - - case PaymentResult.SETTLED: - # payment successful - if payment.fee: - melt_quote.fee_paid = payment.fee.to( - to_unit=unit, round="up" - ).amount - if payment.preimage: - melt_quote.payment_preimage = payment.preimage - # set quote as paid - melt_quote.state = MeltQuoteState.paid - melt_quote.paid_time = int(time.time()) - # NOTE: This is the only return point for a successful payment - - case PaymentResult.PENDING | _: - logger.debug( - f"Lightning payment is pending: {payment.checking_id}" - ) - return PostMeltQuoteResponse.from_melt_quote(melt_quote) - - # melt successful, invalidate proofs - await self._invalidate_proofs(proofs=proofs, quote_id=melt_quote.quote) - await self.db_write._unset_proofs_pending(proofs) - - # prepare change to compensate wallet for overpaid fees - return_promises: List[BlindedSignature] = [] - if outputs: - return_promises = await self._generate_change_promises( - fee_provided=fee_reserve_provided, - fee_paid=melt_quote.fee_paid, - outputs=outputs, - keyset=self.keysets[outputs[0].id], + melt_quote.checking_id = payment.checking_id + await self.crud.update_melt_quote(quote=melt_quote, db=self.db) + except Exception as e: + logger.error(f"Exception during pay_invoice: {e}") + payment = PaymentResponse( + result=PaymentResult.UNKNOWN, + error_message=str(e), ) - melt_quote.change = return_promises + match payment.result: + case PaymentResult.FAILED | PaymentResult.UNKNOWN: + # explicitly check payment status for failed or unknown payment states + checking_id = payment.checking_id or melt_quote.checking_id + logger.debug( + f"Payment state is {payment.result.name}.{' Error: ' + payment.error_message + '.' if payment.error_message else ''} Checking status for {checking_id}." + ) + try: + status = await self.backends[method][unit].get_payment_status( + checking_id + ) + except Exception as e: + # Something went wrong. We might have lost connection to the backend. Keep transaction pending and return. + logger.error( + f"Lightning backend error: could not check payment status. Proofs for melt quote {melt_quote.quote} are stuck as PENDING. Disabling melt. Fix your Lightning backend and restart the mint.\nError: {e}" + ) + self.disable_melt = True + return PostMeltQuoteResponse.from_melt_quote(melt_quote) - await self.crud.update_melt_quote(quote=melt_quote, db=self.db) - await self.events.submit(melt_quote) + match status.result: + case PaymentResult.FAILED | PaymentResult.UNKNOWN: + # Everything as expected. Payment AND a status check both agree on a failure. We roll back the transaction. + await self.db_write._unset_proofs_pending(proofs) + await self.db_write._unset_melt_quote_pending( + quote=melt_quote, state=previous_state + ) + if status.error_message: + logger.error( + f"Status check error: {status.error_message}" + ) + raise LightningError( + f"Lightning payment failed{': ' + payment.error_message if payment.error_message else ''}." + ) + case _: + # Something went wrong with our implementation or the backend. Status check returned different result than payment. Keep transaction pending and return. + logger.error( + f"Payment state is {status.result.name} and payment was {payment.result}. Proofs for melt quote {melt_quote.quote} are stuck as PENDING. Disabling melt. Fix your Lightning backend and restart the mint." + ) + self.disable_melt = True + return PostMeltQuoteResponse.from_melt_quote(melt_quote) - return PostMeltQuoteResponse.from_melt_quote(melt_quote) + case PaymentResult.SETTLED: + # payment successful + if payment.fee: + melt_quote.fee_paid = payment.fee.to( + to_unit=unit, round="up" + ).amount + if payment.preimage: + melt_quote.payment_preimage = payment.preimage + # set quote as paid + melt_quote.state = MeltQuoteState.paid + melt_quote.paid_time = int(time.time()) + # NOTE: This is the only branch for a successful payment - except Exception as e: - logger.trace(f"Payment has failed: {e}") - await self.db_write._unset_proofs_pending(proofs) - await self.db_write._unset_melt_quote_pending( - quote=melt_quote, state=previous_state + case PaymentResult.PENDING | _: + logger.debug( + f"Lightning payment is {payment.result.name}: {payment.checking_id}" + ) + return PostMeltQuoteResponse.from_melt_quote(melt_quote) + + # melt was successful (either internal or via backend), invalidate proofs + await self._invalidate_proofs(proofs=proofs, quote_id=melt_quote.quote) + await self.db_write._unset_proofs_pending(proofs) + + # prepare change to compensate wallet for overpaid fees + return_promises: List[BlindedSignature] = [] + if outputs: + return_promises = await self._generate_change_promises( + fee_provided=fee_reserve_provided, + fee_paid=melt_quote.fee_paid, + outputs=outputs, + keyset=self.keysets[outputs[0].id], ) - raise e + + melt_quote.change = return_promises + + await self.crud.update_melt_quote(quote=melt_quote, db=self.db) + await self.events.submit(melt_quote) + + return PostMeltQuoteResponse.from_melt_quote(melt_quote) async def swap( self, diff --git a/tests/test_mint_melt.py b/tests/test_mint_melt.py index 1a99f20..8d2d248 100644 --- a/tests/test_mint_melt.py +++ b/tests/test_mint_melt.py @@ -295,3 +295,39 @@ async def test_melt_lightning_pay_invoice_failed_pending( # expect that proofs are pending states = await ledger.db_read.get_proofs_states([p.Y for p in wallet.proofs]) assert all([s.pending for s in states]) + + +@pytest.mark.asyncio +@pytest.mark.skipif(is_regtest, reason="only fake wallet") +async def test_melt_lightning_pay_invoice_exception_exception( + ledger: Ledger, wallet: Wallet +): + """Simulates the case where pay_invoice and get_payment_status raise an exception (due to network issues for example).""" + invoice = await wallet.request_mint(64) + await ledger.get_mint_quote(invoice.id) # fakewallet: set the quote to paid + await wallet.mint(64, id=invoice.id) + # invoice_64_sat = "lnbcrt640n1pn0r3tfpp5e30xac756gvd26cn3tgsh8ug6ct555zrvl7vsnma5cwp4g7auq5qdqqcqzzsxqyz5vqsp5xfhtzg0y3mekv6nsdnj43c346smh036t4f8gcfa2zwpxzwcryqvs9qxpqysgqw5juev8y3zxpdu0mvdrced5c6a852f9x7uh57g6fgjgcg5muqzd5474d7xgh770frazel67eejfwelnyr507q46hxqehala880rhlqspw07ta0" + invoice_62_sat = "lnbcrt620n1pn0r3vepp5zljn7g09fsyeahl4rnhuy0xax2puhua5r3gspt7ttlfrley6valqdqqcqzzsxqyz5vqsp577h763sel3q06tfnfe75kvwn5pxn344sd5vnays65f9wfgx4fpzq9qxpqysgqg3re9afz9rwwalytec04pdhf9mvh3e2k4r877tw7dr4g0fvzf9sny5nlfggdy6nduy2dytn06w50ls34qfldgsj37x0ymxam0a687mspp0ytr8" + quote_id = ( + await ledger.melt_quote( + PostMeltQuoteRequest(unit="sat", request=invoice_62_sat) + ) + ).quote + # quote = await ledger.get_melt_quote(quote_id) + settings.fakewallet_payment_state_exception = True + settings.fakewallet_pay_invoice_state_exception = True + + # we expect a pending melt quote because something has gone wrong (for example has lost connection to backend) + resp = await ledger.melt(proofs=wallet.proofs, quote=quote_id) + assert resp.state == MeltQuoteState.pending.value + + # the mint should be locked now and not allow any other melts until it is restarted + quote_id = ( + await ledger.melt_quote( + PostMeltQuoteRequest(unit="sat", request=invoice_62_sat) + ) + ).quote + await assert_err( + ledger.melt(proofs=wallet.proofs, quote=quote_id), + "Melt is disabled. Please contact the operator.", + )