fix htlc forwarding:

- persist fail_htlc error messages
 - do not rely on payment_hash in htlc_switch

electrum/lnchannel.py

@@ -48,7 +48,7 @@ from .lnutil import (Outpoint, LocalConfig, RemoteConfig, Keypair, OnlyPubkeyKey
                      HTLC_TIMEOUT_WEIGHT, HTLC_SUCCESS_WEIGHT, extract_ctn_from_tx_and_chan, UpdateAddHtlc,
                      funding_output_script, SENT, RECEIVED, LOCAL, REMOTE, HTLCOwner, make_commitment_outputs,
                      ScriptHtlc, PaymentFailure, calc_fees_for_commitment_tx, RemoteMisbehaving, make_htlc_output_witness_script,
-                     ShortChannelID, map_htlcs_to_ctx_output_idxs, LNPeerAddr, BarePaymentAttemptLog,
+                     ShortChannelID, map_htlcs_to_ctx_output_idxs, LNPeerAddr,
                      LN_MAX_HTLC_VALUE_MSAT, fee_for_htlc_output, offered_htlc_trim_threshold_sat,
                      received_htlc_trim_threshold_sat)
 from .lnsweep import create_sweeptxs_for_our_ctx, create_sweeptxs_for_their_ctx
@@ -482,7 +482,7 @@ class Channel(AbstractChannel):
         self._chan_ann_without_sigs = None  # type: Optional[bytes]
         self.revocation_store = RevocationStore(state["revocation_store"])
         self._can_send_ctx_updates = True  # type: bool
-        self._receive_fail_reasons = {}  # type: Dict[int, BarePaymentAttemptLog]
+        self._receive_fail_reasons = {}  # type: Dict[int, (bytes, OnionRoutingFailureMessage)]
         self._ignore_max_htlc_value = False  # used in tests
 
     def is_initiator(self):
@@ -953,8 +953,23 @@ class Channel(AbstractChannel):
                 self.lnworker.payment_sent(self, htlc.payment_hash)
             failed = self.hm.failed_in_ctn(new_ctn)
             for htlc in failed:
-                payment_attempt = self._receive_fail_reasons.get(htlc.htlc_id)
+                error_bytes, failure_message = self._receive_fail_reasons.pop(htlc.htlc_id)
-                self.lnworker.payment_failed(self, htlc.payment_hash, payment_attempt)
+                # if we are forwarding, save error message to disk
+                if self.lnworker.get_payment_info(htlc.payment_hash) is None:
+                    self.save_fail_htlc_reason(htlc.htlc_id, error_bytes, failure_message)
+                else:
+                    self.lnworker.payment_failed(self, htlc.payment_hash, error_bytes, failure_message)
+
+    def save_fail_htlc_reason(self, htlc_id, error_bytes, failure_message):
+        error_hex = error_bytes.hex() if error_bytes else None
+        failure_hex = failure_message.to_bytes().hex() if failure_message else None
+        self.hm.log['fail_htlc_reasons'][htlc_id] = (error_hex, failure_hex)
+
+    def pop_fail_htlc_reason(self, htlc_id):
+        error_hex, failure_hex = self.hm.log['fail_htlc_reasons'].pop(htlc_id, (None, None))
+        error_bytes = bytes.fromhex(error_hex) if error_hex else None
+        failure_message = OnionRoutingFailureMessage.from_bytes(bytes.fromhex(failure_hex)) if failure_hex else None
+        return error_bytes, failure_message
 
     def extract_preimage_from_htlc_tx(self, tx):
         witness = tx.inputs()[0].witness_elements()
@@ -1185,10 +1200,7 @@ class Channel(AbstractChannel):
         self.logger.info("receive_fail_htlc")
         with self.db_lock:
             self.hm.recv_fail(htlc_id)
-        self._receive_fail_reasons[htlc_id] = BarePaymentAttemptLog(success=False,
+        self._receive_fail_reasons[htlc_id] = (error_bytes, reason)
-                                                                    preimage=None,
-                                                                    error_bytes=error_bytes,
-                                                                    error_reason=reason)
 
     def get_next_fee(self, subject: HTLCOwner) -> int:
         return self.constraints.capacity - sum(x.value for x in self.get_next_commitment(subject).outputs())

electrum/lnhtlc.py

@@ -29,6 +29,8 @@ class HTLCManager:
 
         if 'unfulfilled_htlcs' not in log:
             log['unfulfilled_htlcs'] = {}  # htlc_id -> onion_packet
+        if 'fail_htlc_reasons' not in log:
+            log['fail_htlc_reasons'] = {}  # htlc_id -> error_bytes, failure_message
 
         # maybe bootstrap fee_updates if initial_feerate was provided
         if initial_feerate is not None:

electrum/lnonion.py

@@ -395,6 +395,16 @@ class OnionRoutingFailureMessage:
         ret += self.data
         return ret
 
+    @classmethod
+    def from_bytes(cls, failure_msg: bytes):
+        failure_code = int.from_bytes(failure_msg[:2], byteorder='big')
+        try:
+            failure_code = OnionFailureCode(failure_code)
+        except ValueError:
+            pass  # uknown failure code
+        failure_data = failure_msg[2:]
+        return OnionRoutingFailureMessage(failure_code, failure_data)
+
 
 def construct_onion_error(reason: OnionRoutingFailureMessage,
                           onion_packet: OnionPacket,
@@ -450,13 +460,8 @@ def get_failure_msg_from_onion_error(decrypted_error_packet: bytes) -> OnionRout
     failure_len = int.from_bytes(decrypted_error_packet[32:34], byteorder='big')
     failure_msg = decrypted_error_packet[34:34+failure_len]
     # create failure message object
-    failure_code = int.from_bytes(failure_msg[:2], byteorder='big')
+    return OnionRoutingFailureMessage.from_bytes(failure_msg)
-    try:
+
-        failure_code = OnionFailureCode(failure_code)
-    except ValueError:
-        pass  # uknown failure code
-    failure_data = failure_msg[2:]
-    return OnionRoutingFailureMessage(failure_code, failure_data)
 
 
 # TODO maybe we should rm this and just use OnionWireSerializer and onion_wire.csv

electrum/lnpeer.py

@@ -1141,56 +1141,56 @@ class Peer(Logger):
 
     def maybe_forward_htlc(self, chan: Channel, htlc: UpdateAddHtlc, *,
                            onion_packet: OnionPacket, processed_onion: ProcessedOnionPacket
-                           ) -> Optional[OnionRoutingFailureMessage]:
+                           ) -> Tuple[Optional[bytes], Optional[int], Optional[OnionRoutingFailureMessage]]:
         # Forward HTLC
         # FIXME: there are critical safety checks MISSING here
         forwarding_enabled = self.network.config.get('lightning_forward_payments', False)
         if not forwarding_enabled:
             self.logger.info(f"forwarding is disabled. failing htlc.")
-            return OnionRoutingFailureMessage(code=OnionFailureCode.PERMANENT_CHANNEL_FAILURE, data=b'')
+            return None, None, OnionRoutingFailureMessage(code=OnionFailureCode.PERMANENT_CHANNEL_FAILURE, data=b'')
         chain = self.network.blockchain()
         if chain.is_tip_stale():
             return OnionRoutingFailureMessage(code=OnionFailureCode.TEMPORARY_NODE_FAILURE, data=b'')
         try:
             next_chan_scid = processed_onion.hop_data.payload["short_channel_id"]["short_channel_id"]
         except:
-            return OnionRoutingFailureMessage(code=OnionFailureCode.INVALID_ONION_PAYLOAD, data=b'\x00\x00\x00')
+            return None, None, OnionRoutingFailureMessage(code=OnionFailureCode.INVALID_ONION_PAYLOAD, data=b'\x00\x00\x00')
         next_chan = self.lnworker.get_channel_by_short_id(next_chan_scid)
         local_height = chain.height()
         if next_chan is None:
             self.logger.info(f"cannot forward htlc. cannot find next_chan {next_chan_scid}")
-            return OnionRoutingFailureMessage(code=OnionFailureCode.UNKNOWN_NEXT_PEER, data=b'')
+            return None, None, OnionRoutingFailureMessage(code=OnionFailureCode.UNKNOWN_NEXT_PEER, data=b'')
         outgoing_chan_upd = next_chan.get_outgoing_gossip_channel_update()[2:]
         outgoing_chan_upd_len = len(outgoing_chan_upd).to_bytes(2, byteorder="big")
         if not next_chan.can_send_update_add_htlc():
             self.logger.info(f"cannot forward htlc. next_chan {next_chan_scid} cannot send ctx updates. "
                              f"chan state {next_chan.get_state()!r}, peer state: {next_chan.peer_state!r}")
             data = outgoing_chan_upd_len + outgoing_chan_upd
-            return OnionRoutingFailureMessage(code=OnionFailureCode.TEMPORARY_CHANNEL_FAILURE, data=data)
+            return None, None, OnionRoutingFailureMessage(code=OnionFailureCode.TEMPORARY_CHANNEL_FAILURE, data=data)
         try:
             next_cltv_expiry = processed_onion.hop_data.payload["outgoing_cltv_value"]["outgoing_cltv_value"]
         except:
-            return OnionRoutingFailureMessage(code=OnionFailureCode.INVALID_ONION_PAYLOAD, data=b'\x00\x00\x00')
+            return None, None, OnionRoutingFailureMessage(code=OnionFailureCode.INVALID_ONION_PAYLOAD, data=b'\x00\x00\x00')
         if htlc.cltv_expiry - next_cltv_expiry < NBLOCK_OUR_CLTV_EXPIRY_DELTA:
             data = htlc.cltv_expiry.to_bytes(4, byteorder="big") + outgoing_chan_upd_len + outgoing_chan_upd
-            return OnionRoutingFailureMessage(code=OnionFailureCode.INCORRECT_CLTV_EXPIRY, data=data)
+            return None, None, OnionRoutingFailureMessage(code=OnionFailureCode.INCORRECT_CLTV_EXPIRY, data=data)
         if htlc.cltv_expiry - lnutil.MIN_FINAL_CLTV_EXPIRY_ACCEPTED <= local_height \
                 or next_cltv_expiry <= local_height:
             data = outgoing_chan_upd_len + outgoing_chan_upd
-            return OnionRoutingFailureMessage(code=OnionFailureCode.EXPIRY_TOO_SOON, data=data)
+            return None, None, OnionRoutingFailureMessage(code=OnionFailureCode.EXPIRY_TOO_SOON, data=data)
         if max(htlc.cltv_expiry, next_cltv_expiry) > local_height + lnutil.NBLOCK_CLTV_EXPIRY_TOO_FAR_INTO_FUTURE:
-            return OnionRoutingFailureMessage(code=OnionFailureCode.EXPIRY_TOO_FAR, data=b'')
+            return None, OnionRoutingFailureMessage(code=OnionFailureCode.EXPIRY_TOO_FAR, data=b'')
         try:
             next_amount_msat_htlc = processed_onion.hop_data.payload["amt_to_forward"]["amt_to_forward"]
         except:
-            return OnionRoutingFailureMessage(code=OnionFailureCode.INVALID_ONION_PAYLOAD, data=b'\x00\x00\x00')
+            return None, None, OnionRoutingFailureMessage(code=OnionFailureCode.INVALID_ONION_PAYLOAD, data=b'\x00\x00\x00')
         forwarding_fees = fee_for_edge_msat(
             forwarded_amount_msat=next_amount_msat_htlc,
             fee_base_msat=lnutil.OUR_FEE_BASE_MSAT,
             fee_proportional_millionths=lnutil.OUR_FEE_PROPORTIONAL_MILLIONTHS)
         if htlc.amount_msat - next_amount_msat_htlc < forwarding_fees:
             data = next_amount_msat_htlc.to_bytes(8, byteorder="big") + outgoing_chan_upd_len + outgoing_chan_upd
-            return OnionRoutingFailureMessage(code=OnionFailureCode.FEE_INSUFFICIENT, data=data)
+            return None, None, OnionRoutingFailureMessage(code=OnionFailureCode.FEE_INSUFFICIENT, data=data)
         self.logger.info(f'forwarding htlc to {next_chan.node_id}')
         next_htlc = UpdateAddHtlc(
             amount_msat=next_amount_msat_htlc,
@@ -1213,7 +1213,7 @@ class Peer(Logger):
             self.logger.info(f"failed to forward htlc: error sending message. {e}")
             data = outgoing_chan_upd_len + outgoing_chan_upd
             return OnionRoutingFailureMessage(code=OnionFailureCode.TEMPORARY_CHANNEL_FAILURE, data=data)
-        return None
+        return next_chan_scid, next_htlc.htlc_id, None
 
     def maybe_fulfill_htlc(self, *, chan: Channel, htlc: UpdateAddHtlc,
                            onion_packet: OnionPacket, processed_onion: ProcessedOnionPacket,
@@ -1470,6 +1470,7 @@ class Peer(Logger):
         await self.network.try_broadcasting(closing_tx, 'closing')
         return closing_tx.txid()
 
+    @log_exceptions
     async def htlc_switch(self):
         await self.initialized
         while True:
@@ -1481,7 +1482,7 @@ class Peer(Logger):
                 self.maybe_send_commitment(chan)
                 done = set()
                 unfulfilled = chan.hm.log.get('unfulfilled_htlcs', {})
-                for htlc_id, (local_ctn, remote_ctn, onion_packet_hex, forwarded) in unfulfilled.items():
+                for htlc_id, (local_ctn, remote_ctn, onion_packet_hex, forwarding_info) in unfulfilled.items():
                     if chan.get_oldest_unrevoked_ctn(LOCAL) <= local_ctn:
                         continue
                     if chan.get_oldest_unrevoked_ctn(REMOTE) <= remote_ctn:
@@ -1514,23 +1515,21 @@ class Peer(Logger):
                                 htlc=htlc,
                                 onion_packet=onion_packet,
                                 processed_onion=processed_onion)
-                        elif not forwarded:
+                        elif not forwarding_info:
-                            error_reason = self.maybe_forward_htlc(
+                            next_chan_id, next_htlc_id, error_reason = self.maybe_forward_htlc(
                                 chan=chan,
                                 htlc=htlc,
                                 onion_packet=onion_packet,
                                 processed_onion=processed_onion)
-                            if not error_reason:
+                            if next_chan_id:
-                                unfulfilled[htlc_id] = local_ctn, remote_ctn, onion_packet_hex, True
+                                fw_info = (next_chan_id.hex(), next_htlc_id)
+                                unfulfilled[htlc_id] = local_ctn, remote_ctn, onion_packet_hex, fw_info
                         else:
-                            # TODO self.lnworker.pending_payments is not persisted,
+                            preimage = self.lnworker.get_preimage(payment_hash)
-                            #      so what happens if we restart the process?...
+                            next_chan_id_hex, htlc_id = forwarding_info
-                            f = self.lnworker.pending_payments[payment_hash]
+                            next_chan = self.lnworker.get_channel_by_short_id(bytes.fromhex(next_chan_id_hex))
-                            if f.done():
+                            if next_chan:
-                                payment_attempt = f.result()
+                                error_bytes, error_reason = next_chan.pop_fail_htlc_reason(htlc_id)
-                                preimage = payment_attempt.preimage
-                                error_bytes = payment_attempt.error_bytes
-                                error_reason = payment_attempt.error_reason
                         if preimage:
                             await self.lnworker.enable_htlc_settle.wait()
                             self.fulfill_htlc(chan, htlc.htlc_id, preimage)

electrum/lnutil.py

@@ -235,9 +235,9 @@ class PaymentAttemptLog(NamedTuple):
 
 class BarePaymentAttemptLog(NamedTuple):
     success: bool
-    preimage: Optional[bytes]
+    preimage: Optional[bytes] = None
-    error_bytes: Optional[bytes]
+    error_bytes: Optional[bytes] = None
-    error_reason: Optional['OnionRoutingFailureMessage'] = None
+    failure_message: Optional['OnionRoutingFailureMessage'] = None
 
 
 class LightningError(Exception): pass

electrum/lnworker.py

@@ -1105,10 +1105,11 @@ class LNWallet(LNWorker):
         self.preimages[bh2u(payment_hash)] = bh2u(preimage)
         self.wallet.save_db()
 
-    def get_preimage(self, payment_hash: bytes) -> bytes:
+    def get_preimage(self, payment_hash: bytes) -> Optional[bytes]:
-        return bfh(self.preimages.get(bh2u(payment_hash)))
+        r = self.preimages.get(bh2u(payment_hash))
+        return bfh(r) if r else None
 
-    def get_payment_info(self, payment_hash: bytes) -> PaymentInfo:
+    def get_payment_info(self, payment_hash: bytes) -> Optional[PaymentInfo]:
         key = payment_hash.hex()
         with self.lock:
             if key in self.payments:
@@ -1157,14 +1158,18 @@ class LNWallet(LNWorker):
         info = info._replace(status=status)
         self.save_payment_info(info)
 
-    def payment_failed(self, chan, payment_hash: bytes, payment_attempt: BarePaymentAttemptLog):
+    def payment_failed(self, chan, payment_hash: bytes, error_bytes: bytes, failure_message):
         self.set_payment_status(payment_hash, PR_UNPAID)
-        key = payment_hash.hex()
         f = self.pending_payments.get(payment_hash)
         if f and not f.cancelled():
+            payment_attempt = BarePaymentAttemptLog(
+                success=False,
+                error_bytes=error_bytes,
+                failure_message=failure_message)
             f.set_result(payment_attempt)
         else:
             chan.logger.info('received unexpected payment_failed, probably from previous session')
+            key = payment_hash.hex()
             util.trigger_callback('invoice_status', key)
             util.trigger_callback('payment_failed', key, '')
         util.trigger_callback('ln_payment_failed', payment_hash, chan.channel_id)
@@ -1172,15 +1177,15 @@ class LNWallet(LNWorker):
     def payment_sent(self, chan, payment_hash: bytes):
         self.set_payment_status(payment_hash, PR_PAID)
         preimage = self.get_preimage(payment_hash)
-        key = payment_hash.hex()
         f = self.pending_payments.get(payment_hash)
         if f and not f.cancelled():
-            payment_attempt = BarePaymentAttemptLog(success=True,
+            payment_attempt = BarePaymentAttemptLog(
-                                                    preimage=preimage,
+                success=True,
-                                                    error_bytes=None)
+                preimage=preimage)
             f.set_result(payment_attempt)
         else:
             chan.logger.info('received unexpected payment_sent, probably from previous session')
+            key = payment_hash.hex()
             util.trigger_callback('invoice_status', key)
             util.trigger_callback('payment_succeeded', key)
         util.trigger_callback('ln_payment_completed', payment_hash, chan.channel_id)