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

question about CHANNEL_ERR_TOO_MANY_HTLCS #3953

Closed
mloop1 opened this issue Aug 17, 2020 · 4 comments · Fixed by #4432
Closed

question about CHANNEL_ERR_TOO_MANY_HTLCS #3953

mloop1 opened this issue Aug 17, 2020 · 4 comments · Fixed by #4432
Assignees
@rustyrussell
Labels
bug
Milestone
v0.9.4

Comments

@mloop1
Copy link

mloop1 commented Aug 17, 2020 •
edited
Loading

Hi,
one of my channel with a stable and reliable peer has been unilaterally closed by my node with this status:
CHANNELD_NORMAL:Bad peer_add_htlc: CHANNEL_ERR_TOO_MANY_HTLCS
I was wondering under which circustamces this could happen?

I'm running "version": "v0.9.0-1" on mainnet.
@rustyrussell rustyrussell added this to the v0.9.1 milestone Sep 10, 2020
@rustyrussell rustyrussell self-assigned this Sep 10, 2020
@rustyrussell
Copy link
Contributor

It should not. It closed on you because you sent more HTLCs than it allows (which you should never do).

I've tried various scenarios and I cannot reproduce this :( Any more information on what you were doing?

@mloop1
Copy link
Author

mloop1 commented Sep 10, 2020 •
edited
Loading

It should not. It closed on you because you sent more HTLCs than it allows (which you should never do).

I've tried various scenarios and I cannot reproduce this :( Any more information on what you were doing?

Hi Rusty, thanks for getting back to me.
I was doing nothing while this happened.
Here some more logs, hope this helps.
I also have the output from "listpeers" when the channel was in state "ONCHAIN" with the array of "htlcs", can send that as well if it can help.

2020-08-17T11:04:33.650Z UNUSUAL 03a503d8e30f2ff407096d235b5db63b4fcf3f89a653acb6f43d3fc492a7674019-channeld-chan#39763: Adding HTLC too slow: killing connection 2020-08-17T11:04:33.651Z INFO 03a503d8e30f2ff407096d235b5db63b4fcf3f89a653acb6f43d3fc492a7674019-chan#39763: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channe ld died (9) 2020-08-17T11:05:24.837Z UNUSUAL 03a503d8e30f2ff407096d235b5db63b4fcf3f89a653acb6f43d3fc492a7674019-chan#39763: Peer permanent failure in CHANNELD_NORMAL: channeld: sent ERROR Bad peer_ add_htlc: CHANNEL_ERR_TOO_MANY_HTLCS 2020-08-17T11:05:24.841Z INFO 03a503d8e30f2ff407096d235b5db63b4fcf3f89a653acb6f43d3fc492a7674019-chan#39763: State changed from CHANNELD_NORMAL to AWAITING_UNILATERAL

@whitslack
Copy link
Collaborator

My C-Lightning v0.9.0-1 node did the same thing a few days ago.

2020-09-10T04:06:57.055Z DEBUG 03…09-channeld-chan#139759: NEW:: HTLC LOCAL 8 = SENT_ADD_HTLC/RCVD_ADD_HTLC 
2020-09-10T04:06:57.056Z DEBUG 03…09-channeld-chan#139759: Adding HTLC 8 amount=157720268msat cltv=647737 gave CHANNEL_ERR_ADD_OK
2020-09-10T04:06:57.056Z DEBUG 03…09-channeld-chan#139759: peer_out WIRE_UPDATE_ADD_HTLC
2020-09-10T04:06:57.056Z DEBUG 03…09-channeld-chan#139759: REPLY WIRE_CHANNEL_OFFER_HTLC_REPLY with 0 fds
2020-09-10T04:06:57.066Z DEBUG 03…09-channeld-chan#139759: Trying commit
2020-09-10T04:06:57.066Z DEBUG 03…09-channeld-chan#139759: htlc 8: SENT_ADD_HTLC->SENT_ADD_COMMIT
2020-09-10T04:06:57.066Z DEBUG 03…09-channeld-chan#139759: htlc added REMOTE: local 3964971689 remote 4513136181
2020-09-10T04:06:57.066Z DEBUG 03…09-channeld-chan#139759: -> local 3807251421 remote 4513136181
2020-09-10T04:06:57.067Z DEBUG 03…09-channeld-chan#139759: sending_commit: HTLC LOCAL 8 = SENT_ADD_COMMIT/RCVD_ADD_COMMIT 
2020-09-10T04:06:57.068Z DEBUG 03…09-channeld-chan#139759: Creating commit_sig signature 149 30…01 for tx 02…20 wscript 52…ae key 03…69
2020-09-10T04:06:57.070Z DEBUG 03…09-channeld-chan#139759: Creating HTLC signature 30…01 for tx 02…00 wscript 76…68 key 03…5c
2020-09-10T04:06:57.071Z DEBUG 03…09-channeld-chan#139759: Creating HTLC signature 30…01 for tx 02…00 wscript 76…68 key 03…5c
2020-09-10T04:06:57.073Z DEBUG 03…09-channeld-chan#139759: Creating HTLC signature 30…01 for tx 02…00 wscript 76…68 key 03…5c
2020-09-10T04:06:57.074Z DEBUG 03…09-channeld-chan#139759: Creating HTLC signature 30…01 for tx 02…00 wscript 76…68 key 03…5c
2020-09-10T04:06:57.075Z DEBUG 03…09-channeld-chan#139759: Creating HTLC signature 30…01 for tx 02…00 wscript 76…68 key 03…5c
2020-09-10T04:06:57.075Z DEBUG 03…09-channeld-chan#139759: Telling master we're about to commit...
2020-09-10T04:06:57.076Z DEBUG 03…09-channeld-chan#139759: Sending master 1020
2020-09-10T04:06:57.077Z DEBUG 03…09-chan#139759: HTLC out 8 SENT_ADD_HTLC->SENT_ADD_COMMIT
2020-09-10T04:06:57.145Z DEBUG 03…09-channeld-chan#139759: ... , awaiting 1120
2020-09-10T04:06:57.145Z DEBUG 03…09-channeld-chan#139759: Got it!
2020-09-10T04:06:57.146Z DEBUG 03…09-channeld-chan#139759: Sending commit_sig with 5 htlc sigs
2020-09-10T04:06:57.146Z DEBUG 03…09-channeld-chan#139759: peer_out WIRE_COMMITMENT_SIGNED
2020-09-10T04:06:57.560Z DEBUG 03…09-channeld-chan#139759: peer_in WIRE_REVOKE_AND_ACK
2020-09-10T04:06:57.560Z DEBUG 03…09-channeld-chan#139759: Received revoke_and_ack
2020-09-10T04:06:57.561Z DEBUG 03…09-channeld-chan#139759: htlc 8: SENT_ADD_COMMIT->RCVD_ADD_REVOCATION
2020-09-10T04:06:57.561Z DEBUG 03…09-channeld-chan#139759: rcvd_revoke_and_ack: HTLC LOCAL 8 = RCVD_ADD_REVOCATION/SENT_ADD_REVOCATION 
2020-09-10T04:06:57.561Z DEBUG 03…09-channeld-chan#139759: Commits outstanding after recv revoke_and_ack
2020-09-10T04:06:57.562Z DEBUG 03…09-channeld-chan#139759: HTLC 8[LOCAL] => RCVD_ADD_REVOCATION
2020-09-10T04:06:57.563Z DEBUG 03…09-channeld-chan#139759: Sending master 1022
2020-09-10T04:06:57.564Z DEBUG 03…09-chan#139759: got revoke 148: 1 changed
2020-09-10T04:06:57.564Z DEBUG 03…09-chan#139759: HTLC out 8 SENT_ADD_COMMIT->RCVD_ADD_REVOCATION
2020-09-10T04:06:57.634Z DEBUG 03…09-channeld-chan#139759: ... , awaiting 1122
2020-09-10T04:06:57.634Z DEBUG 03…09-channeld-chan#139759: Got it!
2020-09-10T04:06:57.634Z DEBUG 03…09-channeld-chan#139759: revoke_and_ack REMOTE: remote_per_commit = 02…bf, old_remote_per_commit = 02…53
2020-09-10T04:06:57.634Z DEBUG 03…09-channeld-chan#139759: Trying commit
2020-09-10T04:06:57.635Z DEBUG 03…09-channeld-chan#139759: Can't send commit: nothing to send
2020-09-10T04:06:57.703Z DEBUG 03…09-channeld-chan#139759: peer_in WIRE_COMMITMENT_SIGNED
2020-09-10T04:06:57.703Z DEBUG 03…09-channeld-chan#139759: Received commit
2020-09-10T04:06:57.703Z DEBUG 03…09-channeld-chan#139759: htlc 8: RCVD_ADD_REVOCATION->RCVD_ADD_ACK_COMMIT
2020-09-10T04:06:57.703Z DEBUG 03…09-channeld-chan#139759: htlc added LOCAL: local 3964971689 remote 4513136181
2020-09-10T04:06:57.704Z DEBUG 03…09-channeld-chan#139759: -> local 3807251421 remote 4513136181
2020-09-10T04:06:57.704Z DEBUG 03…09-channeld-chan#139759: rcvd_commit: HTLC LOCAL 8 = RCVD_ADD_ACK_COMMIT/SENT_ADD_ACK_COMMIT 
2020-09-10T04:06:57.704Z DEBUG 03…09-channeld-chan#139759: Feerates are 22882/22882
2020-09-10T04:06:57.705Z DEBUG 03…09-channeld-chan#139759: We need 136245sat at feerate 22882 for 5 untrimmed htlcs: we have 4513136181msat/4513136181msat
2020-09-10T04:06:57.705Z DEBUG 03…09-channeld-chan#139759: Derived key 02…57 from basepoint 03…35, point 02…d5
2020-09-10T04:06:57.705Z DEBUG 03…09-channeld-chan#139759: Received commit_sig with 5 htlc sigs
2020-09-10T04:06:57.706Z DEBUG 03…09-channeld-chan#139759: Sending revoke_and_ack
2020-09-10T04:06:57.706Z DEBUG 03…09-channeld-chan#139759: htlc 8: RCVD_ADD_ACK_COMMIT->SENT_ADD_ACK_REVOCATION
2020-09-10T04:06:57.706Z DEBUG 03…09-channeld-chan#139759: sending_revoke_and_ack: HTLC LOCAL 8 = SENT_ADD_ACK_REVOCATION/RCVD_ADD_ACK_REVOCATION 
2020-09-10T04:06:57.707Z DEBUG 03…09-channeld-chan#139759: Sending master 1021
2020-09-10T04:06:57.707Z DEBUG 03…09-chan#139759: got commitsig 149: feerate 22882, 0 added, 0 fulfilled, 0 failed, 1 changed
2020-09-10T04:06:57.707Z DEBUG 03…09-chan#139759: HTLC out 8 RCVD_ADD_REVOCATION->RCVD_ADD_ACK_COMMIT
2020-09-10T04:06:57.707Z DEBUG 03…09-chan#139759: HTLC out 8 RCVD_ADD_ACK_COMMIT->SENT_ADD_ACK_REVOCATION
2020-09-10T04:06:57.783Z DEBUG 03…09-channeld-chan#139759: ... , awaiting 1121
2020-09-10T04:06:57.784Z DEBUG 03…09-channeld-chan#139759: Got it!
2020-09-10T04:06:57.784Z DEBUG 03…09-channeld-chan#139759: peer_out WIRE_REVOKE_AND_ACK
2020-09-10T04:08:54.833Z DEBUG 03…09-channeld-chan#139759: Adding HTLC 9 amount=19909463msat cltv=647737 gave CHANNEL_ERR_TOO_MANY_HTLCS
2020-09-10T04:08:54.834Z DEBUG 03…09-channeld-chan#139759: REPLY WIRE_CHANNEL_OFFER_HTLC_REPLY with 0 fds
2020-09-10T04:09:24.821Z UNUSUAL 03…09-channeld-chan#139759: Adding HTLC too slow: killing connection
2020-09-10T04:09:24.821Z DEBUG 03…09-channeld-chan#139759: Status closed, but not exited. Killing
2020-09-10T04:09:24.822Z INFO 03…09-chan#139759: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (9)
2020-09-10T04:09:24.822Z DEBUG 03…09-chan#139759: Will try reconnect in 1 seconds
2020-09-10T04:09:26.782Z DEBUG 03…09-chan#139759: Will try reconnect in 2 seconds
2020-09-10T04:09:26.782Z DEBUG 03…09-connectd: Failed connected out: [::…5.…2]:50634: Connection establishment: Connection refused. bit…d.onion:9735: opening -1 socket gave Protocol not supported. 
2020-09-10T04:09:27.081Z DEBUG 03…09-connectd: Connect IN
2020-09-10T04:09:27.082Z DEBUG 03…09-connectd: peer_out WIRE_INIT
2020-09-10T04:09:27.232Z DEBUG 03…09-connectd: peer_in WIRE_INIT
2020-09-10T04:09:27.233Z DEBUG 03…09-chan#139759: Peer has reconnected, state CHANNELD_NORMAL
2020-09-10T04:09:27.242Z DEBUG 03…09-channeld-chan#139759: pid 14882, msgfd 95
2020-09-10T04:09:27.243Z DEBUG 03…09-chan#139759: Already have funding locked in (and ready to announce)
2020-09-10T04:09:27.266Z DEBUG 03…09-channeld-chan#139759: init REMOTE: remote_per_commit = 02…bf, old_remote_per_commit = 02…53 next_idx_local = 150 next_idx_remote = 150 revocations_received = 149 feerates { RCVD_ADD_ACK_REVOCATION:22882 } range 253-229455
2020-09-10T04:09:27.266Z DEBUG 03…09-channeld-chan#139759: option_static_remotekey = 1
2020-09-10T04:09:27.267Z DEBUG 03…09-channeld-chan#139759: Restoring HTLC 0/5: id=24 amount=1000007953msat cltv=647573 payment_hash=9f…5b
2020-09-10T04:09:27.268Z DEBUG 03…09-channeld-chan#139759: NEW:: HTLC REMOTE 24 = RCVD_ADD_ACK_REVOCATION/SENT_ADD_ACK_REVOCATION 
2020-09-10T04:09:27.268Z DEBUG 03…09-channeld-chan#139759: Restoring HTLC 1/5: id=7 amount=169723525msat cltv=647777 payment_hash=d1…e0
2020-09-10T04:09:27.268Z DEBUG 03…09-channeld-chan#139759: NEW:: HTLC LOCAL 7 = SENT_ADD_ACK_REVOCATION/RCVD_ADD_ACK_REVOCATION 
2020-09-10T04:09:27.269Z DEBUG 03…09-channeld-chan#139759: Restoring HTLC 2/5: id=5 amount=173868048msat cltv=647737 payment_hash=d1…e0
2020-09-10T04:09:27.269Z DEBUG 03…09-channeld-chan#139759: NEW:: HTLC LOCAL 5 = SENT_ADD_ACK_REVOCATION/RCVD_ADD_ACK_REVOCATION 
2020-09-10T04:09:27.269Z DEBUG 03…09-channeld-chan#139759: Restoring HTLC 3/5: id=8 amount=157720268msat cltv=647737 payment_hash=d1…e0
2020-09-10T04:09:27.270Z DEBUG 03…09-channeld-chan#139759: NEW:: HTLC LOCAL 8 = SENT_ADD_ACK_REVOCATION/RCVD_ADD_ACK_REVOCATION 
2020-09-10T04:09:27.270Z DEBUG 03…09-channeld-chan#139759: Restoring HTLC 4/5: id=6 amount=178292604msat cltv=647737 payment_hash=d1…e0
2020-09-10T04:09:27.270Z DEBUG 03…09-channeld-chan#139759: NEW:: HTLC LOCAL 6 = SENT_ADD_ACK_REVOCATION/RCVD_ADD_ACK_REVOCATION 
2020-09-10T04:09:27.271Z DEBUG 03…09-channeld-chan#139759: peer_out WIRE_CHANNEL_REESTABLISH
2020-09-10T04:09:27.450Z DEBUG 03…09-channeld-chan#139759: peer_in WIRE_CHANNEL_REESTABLISH
2020-09-10T04:09:27.451Z DEBUG 03…09-channeld-chan#139759: Got reestablish commit=150 revoke=149
2020-09-10T04:09:27.451Z DEBUG 03…09-channeld-chan#139759: next_revocation_number = 149
2020-09-10T04:09:27.451Z DEBUG 03…09-channeld-chan#139759: option_static_remotekey: fields are correct
2020-09-10T04:09:27.452Z DEBUG 03…09-channeld-chan#139759: Exchanging announcement signatures.
2020-09-10T04:09:27.453Z DEBUG 03…09-channeld-chan#139759: peer_out WIRE_ANNOUNCEMENT_SIGNATURES
2020-09-10T04:09:27.557Z DEBUG 03…09-channeld-chan#139759: peer_out WIRE_GOSSIP_TIMESTAMP_FILTER
2020-09-10T04:09:27.557Z DEBUG 03…09-channeld-chan#139759: Trying commit
2020-09-10T04:09:27.570Z DEBUG 03…09-channeld-chan#139759: Can't send commit: nothing to send
2020-09-10T04:45:50.655Z DEBUG 03…09-channeld-chan#139759: peer_in WIRE_UPDATE_ADD_HTLC
2020-09-10T04:45:50.656Z DEBUG 03…09-channeld-chan#139759: peer_out WIRE_ERROR
2020-09-10T04:45:50.657Z UNUSUAL 03…09-chan#139759: Peer permanent failure in CHANNELD_NORMAL: channeld: sent ERROR Bad peer_add_htlc: CHANNEL_ERR_TOO_MANY_HTLCS
2020-09-10T04:45:50.660Z INFO 03…09-chan#139759: State changed from CHANNELD_NORMAL to AWAITING_UNILATERAL

The complete debug history of this channel is attached.

@cdecker cdecker modified the milestones: v0.9.1, v0.9.2 Sep 27, 2020
@niftynei niftynei modified the milestones: v0.9.2, v0.9.3 Nov 10, 2020
@cdecker cdecker modified the milestones: v0.9.3, v0.9.4 Jan 8, 2021
@rustyrussell
Copy link
Contributor

OK, it seems like the checking was too strict: we insisted that they don't pass their own limits, whereas in fact they are allowed to (we're not allowed to pass their limit, they're not allowed to pass ours).

rustyrussell added a commit to rustyrussell/lightning that referenced this issue Mar 16, 2021
@rustyrussell
channeld: allow remote node to exceed their own HTLC count limits.
3bfcd9c 
We try not to exceed either side, but the spec still allows them to
(we don't, but older nodes would have, as could other implementations).

Fixes: ElementsProject#3953
Changelog-Fixed: protocol: overzealous close when peer sent more HTLCs than they'd told us we could send.
Signed-off-by: Rusty Russell <[email protected]>
@rustyrussell rustyrussell mentioned this issue Mar 16, 2021
Merged
rustyrussell added a commit to rustyrussell/lightning that referenced this issue Mar 16, 2021
@rustyrussell
channeld: allow remote node to exceed their own HTLC count limits.
260032b 
We try not to exceed either side, but the spec still allows them to
(we don't, but older nodes would have, as could other implementations).

Fixes: ElementsProject#3953
Changelog-Fixed: protocol: overzealous close when peer sent more HTLCs than they'd told us we could send.
Signed-off-by: Rusty Russell <[email protected]>
rustyrussell added a commit that referenced this issue Mar 16, 2021
@rustyrussell
channeld: allow remote node to exceed their own HTLC count limits.
3fd22f8 
We try not to exceed either side, but the spec still allows them to
(we don't, but older nodes would have, as could other implementations).

Fixes: #3953
Changelog-Fixed: protocol: overzealous close when peer sent more HTLCs than they'd told us we could send.
Signed-off-by: Rusty Russell <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@rustyrussell rustyrussell

Labels
bug
Projects
None yet
Milestone
v0.9.4
Development

Successfully merging a pull request may close this issue.

channeld: allow remote node to exceed their own HTLC count limits. rustyrussell/lightning
5 participants
@cdecker @rustyrussell @whitslack @niftynei @mloop1