CCH successful swaps can emit misleading HoldTlcTimeout errors from settle_tlc_set_command with empty TLC sets

[gpBlockchain]

CCH cross-chain swaps can complete successfully, but Fiber still emits error-level logs like:

cat /Users/guopenglin/PycharmProjects/gp5/fiber-py-integration-test/tmp/fiber/node1/node.log  | grep 0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b
  2026-04-17T09:06:09.913592Z DEBUG fnn::cch::actor: BTC invoice: Bolt11Invoice { signed_invoice: SignedRawBolt11Invoice { raw_invoice: RawBolt11Invoice { hrp: RawHrp { currency: Regtest, raw_amount: Some(10), si_prefix: Some(Micro) }, data: RawDataPart { timestamp: PositiveTimestamp(1776416769s), tagged_fields: [KnownSemantics(PaymentHash(Sha256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b))), KnownSemantics(Description(Description(UntrustedString("test")))), KnownSemantics(MinFinalCltvExpiryDelta(MinFinalCltvExpiryDelta(80))), KnownSemantics(ExpiryTime(ExpiryTime(86400s))), KnownSemantics(PaymentSecret(334736583a491ff67fab947fd74a592580862783b98e7b8d6e8cfbb82a9ea8e1)), KnownSemantics(Features([0, 65, 2, 2]))] } }, hash: [177, 128, 36, 204, 248, 219, 41, 226, 216, 147, 213, 148, 147, 64, 0, 159, 225, 0, 114, 41, 96, 168, 182, 129, 26, 127, 85, 225, 35, 88, 69, 229], signature: Bolt11InvoiceSignature(RecoverableSignature(7ea8edf54016fbb4395a286e386604bdcca1dcc2b87fc00aba18bb5c9580bce915ac4e8917ec5ee45c730d4eddfea2e156d8ca9ffa7bc7c6f97f09e7ad9e282001)) } }
  2026-04-17T09:06:09.915626Z DEBUG fnn::cch::actor: store change event PutCkbInvoiceStatus { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), invoice_status: Open }
  2026-04-17T09:06:09.915662Z DEBUG fnn::cch::scheduler: Scheduled job: ExpireOrder { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), expiry_time: 1776420369 }
  2026-04-17T09:06:09.931844Z ERROR fnn::fiber::settle_tlc_set_command: Remove TLCs for payment hash Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b) because of error HoldTlcTimeout
  2026-04-17T09:06:09.931852Z DEBUG fnn::fiber::settle_tlc_set_command: Removed TLCs for payment hash Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b) because of error HoldTlcTimeout: []
  2026-04-17T09:06:09.931904Z DEBUG fnn::cch::actor: store change event PutCkbInvoiceStatus { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), invoice_status: Received }
  2026-04-17T09:06:09.932294Z DEBUG fnn::cch::scheduler: Scheduled job: ExpireOrder { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), expiry_time: 1776420369 }
  2026-04-17T09:06:09.952347Z DEBUG fnn::cch::actor: event PaymentChanged { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), payment_preimage: None, status: Inflight, failure_reason: None }
  2026-04-17T09:06:09.952688Z DEBUG fnn::cch::scheduler: Scheduled job: ExpireOrder { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), expiry_time: 1776420369 }
  2026-04-17T09:06:10.247001Z DEBUG fnn::cch::actor: event PaymentChanged { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), payment_preimage: Some(Hash256(0x441887593584e21536a89afc278a3581ee3ef699ac82703e8bb13a2efca16f65)), status: Success, failure_reason: None }
  2026-04-17T09:06:10.250352Z DEBUG fnn::cch::scheduler: Scheduled job: ExpireOrder { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), expiry_time: 1776420369 }
  2026-04-17T09:06:10.251169Z DEBUG fnn::cch::actor: store change event PutPreimage { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), payment_preimage: Hash256(0x441887593584e21536a89afc278a3581ee3ef699ac82703e8bb13a2efca16f65) }
  2026-04-17T09:06:10.251628Z ERROR fnn::fiber::settle_tlc_set_command: Remove TLCs for payment hash Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b) because of error HoldTlcTimeout
  2026-04-17T09:06:10.254226Z DEBUG fnn::fiber::settle_tlc_set_command: Removed TLCs for payment hash Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b) because of error HoldTlcTimeout: []
  2026-04-17T09:06:10.254407Z DEBUG fnn::cch::actor: store change event PutPreimage { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), payment_preimage: Hash256(0x441887593584e21536a89afc278a3581ee3ef699ac82703e8bb13a2efca16f65) }
  2026-04-17T09:06:10.278748Z DEBUG fnn::fiber::channel: Removed tlc payment_hash Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b) with reason RemoveTlcFulfill
  2026-04-17T09:06:10.283798Z DEBUG fnn::cch::actor: store change event PutCkbInvoiceStatus { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), invoice_status: Paid }
  2026-04-17T09:06:10.287056Z DEBUG fnn::cch::scheduler: Scheduled job: PruneOrder { payment_hash: Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b), prune_time: 1778234769 }

error

  2026-04-17T09:06:09.931844Z ERROR fnn::fiber::settle_tlc_set_command: Remove TLCs for payment hash Hash256(0x19c9b2e1e824b853c2aa71dd49a11ae442b9414b2a4d08f1a1f20ff582511a4b) because of error HoldTlcTimeout

expected:

1. Why does send_btc return success but keep outputting error logs?

code

    def _assert_send_btc_round_success(self, amount_sats):
        """fiber->cch: fiber2 pay fiber invoice，CCH -> LND。"""
        lnd_invoice = self.LNDs[1].addinvoice(amount_sats)
        send_btc_result = self.fiber1.get_client().send_btc(
            {
                "btc_pay_req": lnd_invoice["payment_request"],
                "currency": "Fibd",
            }
        )

        payment = self.fiber2.get_client().send_payment(
            {"invoice": send_btc_result["incoming_invoice"]["Fiber"]}
        )
        self.wait_payment_state(self.fiber2, payment["payment_hash"], "Success")
        self.wait_cch_order_state(self.fiber1, payment["payment_hash"], "Success")

        order = self.fiber1.get_client().get_cch_order(
            {"payment_hash": payment["payment_hash"]}
        )
        assert order["status"] == "Success"

        decode = self.LNDs[1].ln_cli_with_cmd(
            f"decodepayreq {lnd_invoice['payment_request']}"
        )
        lnd_invoice_state = self.LNDs[1].ln_cli_with_cmd(
            f"lookupinvoice {decode['payment_hash']}"
        )
        assert lnd_invoice_state["state"] == "SETTLED"

[gpBlockchain]

by: codex

CCH cross-chain swaps can complete successfully, but Fiber still emits error-level logs like:

ERROR fnn::fiber::settle_tlc_set_command: Remove TLCs for payment hash ... because of error HoldTlcTimeout
DEBUG fnn::fiber::settle_tlc_set_command: Removed TLCs for payment hash ... because of error HoldTlcTimeout: []

In the observed cases, the swap later proceeds normally:

• incoming invoice transitions to Received
• outgoing payment becomes Inflight
• outgoing payment becomes Success with a preimage
• channel removes TLC with RemoveTlcFulfill
• incoming invoice transitions to Paid

So the error log is misleading: the swap did not fail, and the logged TLC list is empty ([]).

Observed sequence

Example timeline for one payment hash:

1. PutCkbInvoiceStatus(Open)
2. settle_tlc_set_command logs HoldTlcTimeout, but Removed TLCs ...: []
3. PutCkbInvoiceStatus(Received)
4. PaymentChanged(status=Inflight)
5. PaymentChanged(status=Success, payment_preimage=Some(...))
6. PutPreimage(...)
7. settle_tlc_set_command logs HoldTlcTimeout, but again Removed TLCs ...: []
8. fiber::channel logs Removed tlc ... with reason RemoveTlcFulfill
9. PutCkbInvoiceStatus(Paid)

Analysis

This looks like an empty settlement attempt being logged as a real timeout error.

SettleHoldTlcSet(payment_hash) re-reads hold TLCs from store and builds settlement contexts. In the problematic cases, the command reaches the rejection path but the actual TLC vector is empty, so the log says HoldTlcTimeout while the debug payload is [].

That suggests an async/state visibility window such as:

• a hold-settlement trigger fires
• there are no currently materializable TLC settlement contexts for that payment hash
• reject_tlcs() still logs an error even though there is nothing to remove
• the real fulfill path runs shortly afterward and the invoice becomes Paid

Why this is a problem

• It looks like the swap failed even when it succeeded.
• It makes CCH logs noisy and confusing during debugging.
• It can send operators in the wrong direction when diagnosing cross-chain issues.

Suggested fix

One or more of the following would help:

• treat empty TLC sets as a no-op instead of an error path
• do not emit ERROR when tlcs.is_empty()
• downgrade this case to debug! / trace!
• improve the log message to distinguish real timeout removals from empty settlement attempts

Relevant code paths

• crates/fiber-lib/src/fiber/settle_tlc_set_command.rs
• crates/fiber-lib/src/fiber/network.rs (SettleHoldTlcSet / settle_invoice)
• crates/fiber-lib/src/fiber/channel.rs (RemoveTlcFulfill -> invoice becomes Paid)

Reproduction hint

This was observed in CCH BTC<->Fiber swap flow where the order eventually completed successfully (Paid) but HoldTlcTimeout was logged before the final fulfill/remove completed.