Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Unilateral close: Can't find HTLC to resend? #1907

Closed
jb55 opened this issue Sep 3, 2018 · 2 comments
Closed

Unilateral close: Can't find HTLC to resend? #1907

jb55 opened this issue Sep 3, 2018 · 2 comments

Comments

@jb55
Copy link
Collaborator

jb55 commented Sep 3, 2018

I noticed this in my logs when I booted up my node this morning:

grep -e 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 -e HTLC:

2018-09-03T18:03:13.518Z lightningd(16845): Loaded 0 HTLC signatures from DB
2018-09-03T18:03:13.518Z lightningd(16845): Loaded 0 HTLC signatures from DB
2018-09-03T18:03:13.519Z lightningd(16845): Loaded 0 HTLC signatures from DB
2018-09-03T18:03:13.519Z lightningd(16845): Loaded 0 HTLC signatures from DB
2018-09-03T18:03:13.520Z lightningd(16845): Loaded 0 HTLC signatures from DB
2018-09-03T18:03:13.520Z lightningd(16845): Loading HTLCs for channel 3
2018-09-03T18:03:13.520Z lightningd(16845): Restored 0 incoming and 0 outgoing HTLCS
2018-09-03T18:03:13.520Z lightningd(16845): Loading HTLCs for channel 4
2018-09-03T18:03:13.520Z lightningd(16845): Restored 0 incoming and 0 outgoing HTLCS
2018-09-03T18:03:13.520Z lightningd(16845): Loading HTLCs for channel 5
2018-09-03T18:03:13.520Z lightningd(16845): Restored 0 incoming and 0 outgoing HTLCS
2018-09-03T18:03:13.520Z lightningd(16845): Loading HTLCs for channel 7
2018-09-03T18:03:13.520Z lightningd(16845): Restored 0 incoming and 0 outgoing HTLCS
2018-09-03T18:03:13.520Z lightningd(16845): Loading HTLCs for channel 9
2018-09-03T18:03:13.520Z lightningd(16845): Restored 0 incoming and 0 outgoing HTLCS
2018-09-03T18:03:36.125Z lightning_connectd(16869): Connected out for 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469
2018-09-03T18:03:36.309Z lightning_connectd(16869): Connect OUT to 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469
2018-09-03T18:03:36.487Z lightningd(16845): 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: Peer has reconnected, state CHANNELD_NORMAL
2018-09-03T18:03:36.487Z lightningd(16845): lightning_channeld-02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: pid 18672, msgfd 50
2018-09-03T18:03:36.487Z lightningd(16845): 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: Already have funding locked in (and ready to announce)
2018-09-03T18:03:36.497Z lightningd(16845): lightning_channeld-02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: init LOCAL: remote_per_commit = 038e419c2d2988a34a1495d2004ee4eaae68b86f4bc3b80a0fcf43fb0991e502c0, old_remote_per_commit = 039ee77e3545a54926eab220217a9506cebdda1b44dfc4f3d1ac5c535e31e3a17c next_idx_local = 1031 next_idx_remote = 1033 revocations_received = 1031 feerates 4814/4127 (range 253-39580)
2018-09-03T18:03:36.497Z lightningd(16845): lightning_channeld-02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: peer_out WIRE_CHANNEL_REESTABLISH
2018-09-03T18:03:36.685Z lightningd(16845): lightning_channeld-02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: peer_in WIRE_CHANNEL_REESTABLISH
2018-09-03T18:03:36.685Z lightningd(16845): lightning_channeld-02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: Got reestablish commit=1032 revoke=1030
2018-09-03T18:03:36.685Z lightningd(16845): lightning_channeld-02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: next_remote_revocation_number = 1030
2018-09-03T18:03:36.685Z lightningd(16845): lightning_channeld-02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: option_data_loss_protect: can't check their claimed per_commitment_point 039ee77e3545a54926eab220217a9506cebdda1b44dfc4f3d1ac5c535e31e3a17c #1030-1 as we're at 1033
2018-09-03T18:03:36.685Z lightningd(16845): lightning_channeld-02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: option_data_loss_protect: fields are correct
2018-09-03T18:03:36.685Z lightningd(16845): lightning_channeld-02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: Retransmitting commitment, feerate LOCAL=4814 REMOTE=4127
2018-09-03T18:03:36.685Z lightningd(16845): lightning_channeld-02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: peer_out WIRE_ERROR
2018-09-03T18:03:36.685Z lightningd(16845): 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: Peer permanent failure in CHANNELD_NORMAL: lightning_channeld: sent ERROR Can't find HTLC 5 to resend
2018-09-03T18:03:36.686Z lightningd(16845): 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: State changed from CHANNELD_NORMAL to AWAITING_UNILATERAL
2018-09-03T18:03:40.583Z lightningd(16845): 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: Got depth change 0->4618 for cf14fb9af16764dd6ae0a46e3b39219375eeceaac401107faff2d87000003cce
2018-09-03T18:03:40.583Z lightningd(16845): 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: Funding tx cf14fb9af16764dd6ae0a46e3b39219375eeceaac401107faff2d87000003cce depth 4618 of 3
2018-09-03T18:03:40.583Z lightningd(16845): 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 chan #3: Funding tx confirmed, but peer in state AWAITING_UNILATERAL
2018-09-03T18:03:44.123Z lightning_gossipd(16870): Received node_announcement for node 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469

full log: https://jb55.com/s/lightningd-bitcoin-2018-09-03-1103.txt

peer:

{
  "id": "02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469",
  "connected": false,
  "channels": [
    {
      "state": "ONCHAIN",
      "owner": "lightning_onchaind",
      "short_channel_id": "534779:2054:0",
      "channel_id": "ce3c000070d8f2af7f1001c4aaceee759321393b6ea4e06add6467f19afb14cf",
      "funding_txid": "cf14fb9af16764dd6ae0a46e3b39219375eeceaac401107faff2d87000003cce",
      "msatoshi_to_us": 19699784,
      "msatoshi_to_us_min": 19699784,
      "msatoshi_to_us_max": 20000000,
      "msatoshi_total": 20000000,
      "dust_limit_satoshis": 546,
      "max_htlc_value_in_flight_msat": 18446744073709552000,
      "their_channel_reserve_satoshis": 0,
      "our_channel_reserve_satoshis": 546,
      "spendable_msatoshi": 19153784,
      "htlc_minimum_msat": 0,
      "their_to_self_delay": 144,
      "our_to_self_delay": 144,
      "max_accepted_htlcs": 483,
      "status": [
        "CHANNELD_NORMAL:Can't find HTLC 5 to resend",
        "ONCHAIN:Tracking our own unilateral close",
        "ONCHAIN:2 outputs unresolved: in 143 blocks will spend DELAYED_OUTPUT_TO_US (11d3d3abd868e88847b062e210bbb199dda92b807175203735f5e90ac6ac6d2e:0) using OUR_DELAYED_RETURN_TO_WALLET"
      ],
      "in_payments_offered": 0,
      "in_msatoshi_offered": 0,
      "in_payments_fulfilled": 0,
      "in_msatoshi_fulfilled": 0,
      "out_payments_offered": 0,
      "out_msatoshi_offered": 0,
      "out_payments_fulfilled": 0,
      "out_msatoshi_fulfilled": 0
    }
  ]
}
@jb55
Copy link
Collaborator Author

jb55 commented Sep 3, 2018

This is on v0.6.1rc1

rustyrussell added a commit to rustyrussell/lightning that referenced this issue Sep 4, 2018
@rustyrussell
db: save and restore last_sent_commit correctly.
b48b23e 
It's an array: we were only saving the single element; if there was more than
one changed HTLC we'd get a bad signature!

The report in ElementsProject#1907 is probably caused by the other side re-requesting
something we considered already finalized; to avoid this particular error,
we should set the field to NULL if there's no last_sent_commit.

I'm increasingly of the opinion we want to just save all the update
packets to the db and blast them out, instead of doing this
second-guessing dance.

Fixes: ElementsProject#1907
Signed-off-by: Rusty Russell <[email protected]>
rustyrussell added a commit to rustyrussell/lightning that referenced this issue Sep 4, 2018
@rustyrussell
db: save and restore last_sent_commit correctly.
83a195d 
It's an array: we were only saving the single element; if there was more than
one changed HTLC we'd get a bad signature!

The report in ElementsProject#1907 is probably caused by the other side re-requesting
something we considered already finalized; to avoid this particular error,
we should set the field to NULL if there's no last_sent_commit.

I'm increasingly of the opinion we want to just save all the update
packets to the db and blast them out, instead of doing this
second-guessing dance.

Fixes: ElementsProject#1907
Signed-off-by: Rusty Russell <[email protected]>
rustyrussell added a commit to rustyrussell/lightning that referenced this issue Sep 4, 2018
@rustyrussell
db: save and restore last_sent_commit correctly.
975ca3c 
It's an array: we were only saving the single element; if there was more than
one changed HTLC we'd get a bad signature!

The report in ElementsProject#1907 is probably caused by the other side re-requesting
something we considered already finalized; to avoid this particular error,
we should set the field to NULL if there's no last_sent_commit.

I'm increasingly of the opinion we want to just save all the update
packets to the db and blast them out, instead of doing this
second-guessing dance.

Fixes: ElementsProject#1907
Signed-off-by: Rusty Russell <[email protected]>
rustyrussell added a commit to rustyrussell/lightning that referenced this issue Sep 4, 2018
@rustyrussell
db: save and restore last_sent_commit correctly.
02b1313 
It's an array: we were only saving the single element; if there was more than
one changed HTLC we'd get a bad signature!

The report in ElementsProject#1907 is probably caused by the other side re-requesting
something we considered already finalized; to avoid this particular error,
we should set the field to NULL if there's no last_sent_commit.

I'm increasingly of the opinion we want to just save all the update
packets to the db and blast them out, instead of doing this
second-guessing dance.

Fixes: ElementsProject#1907
Signed-off-by: Rusty Russell <[email protected]>
@cdecker cdecker closed this as completed in cefb692 Sep 4, 2018
@jb55
Copy link
Collaborator Author

jb55 commented Sep 4, 2018

that was fast!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@jb55