search

lightningnetwork / lnd

Lightning Network Daemon ⚡️
MIT License
7.63k stars 2.07k forks source link

[bug]: 'go to chain for incoming htlc' indefinitely repeats for every new block #7328

Open JssDWt opened 1 year ago

JssDWt commented 1 year ago

Background

Some sub dust apparently successfully forwarded htlcs are processed by the ChannelArbitrator indefinitely on every new block. Some of them are very old. A random one I found was from August 2021 for example and is being handled in every new block today.

We have some recent yet unexplained force closes where the logs surrounding the force close are swamped with 'go to chain for incoming htlc', which makes me think this behavior could cause other channels to close.

Here's logs from a single htlc that shows this behavior and is recent enough so I still have the initial forwarding log. As you can see it just keeps going forever. The channel is still open.

2023-01-15 01:48:15.581 [INF] HSWC: Forwarded HTLC(HTLC_ID_REDACTED) of 1000 mSAT (fee: 1 mSAT) from IncomingChanID(667056:1723:0) to OutgoingChanID(752223:845:1)
2023-01-15 14:16:12.804 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=10, broadcast_delta=10
2023-01-15 14:28:30.431 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=9, broadcast_delta=10
2023-01-15 14:29:00.583 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=8, broadcast_delta=10
2023-01-15 14:37:24.241 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=7, broadcast_delta=10
2023-01-15 14:46:07.671 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=6, broadcast_delta=10
2023-01-15 14:47:40.523 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=5, broadcast_delta=10
2023-01-15 14:48:15.870 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4, broadcast_delta=10
2023-01-15 14:52:46.201 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=3, broadcast_delta=10
2023-01-15 15:17:13.905 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=2, broadcast_delta=10
2023-01-15 15:26:10.339 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=1, broadcast_delta=10
2023-01-15 15:31:09.136 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=0, broadcast_delta=10
2023-01-15 15:47:50.419 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967295, broadcast_delta=10
2023-01-15 15:57:41.753 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967294, broadcast_delta=10
2023-01-15 15:57:49.117 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967293, broadcast_delta=10
2023-01-15 16:18:45.557 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967292, broadcast_delta=10
2023-01-15 16:42:21.096 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967291, broadcast_delta=10
2023-01-15 16:45:23.216 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967290, broadcast_delta=10
2023-01-15 16:45:42.069 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967289, broadcast_delta=10
2023-01-15 16:53:02.348 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967288, broadcast_delta=10
2023-01-15 17:04:25.756 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967287, broadcast_delta=10
2023-01-15 17:07:50.984 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967286, broadcast_delta=10
2023-01-15 17:08:33.882 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967285, broadcast_delta=10
2023-01-15 17:09:56.050 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967284, broadcast_delta=10
2023-01-15 17:31:08.204 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967283, broadcast_delta=10
2023-01-15 17:32:02.620 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967282, broadcast_delta=10
2023-01-15 17:41:37.763 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967281, broadcast_delta=10
2023-01-15 17:45:46.906 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967280, broadcast_delta=10
2023-01-15 17:53:30.308 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967279, broadcast_delta=10
2023-01-15 17:56:34.766 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967278, broadcast_delta=10
2023-01-15 17:59:58.889 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967277, broadcast_delta=10
2023-01-15 18:03:52.936 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967276, broadcast_delta=10
2023-01-15 18:15:16.155 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967275, broadcast_delta=10
2023-01-15 18:24:57.370 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967274, broadcast_delta=10
2023-01-15 18:45:45.512 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967273, broadcast_delta=10
2023-01-15 18:55:53.586 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967272, broadcast_delta=10
2023-01-15 18:57:02.426 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967271, broadcast_delta=10
2023-01-15 19:14:14.600 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967270, broadcast_delta=10
2023-01-15 19:25:39.251 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967269, broadcast_delta=10
2023-01-15 19:30:27.293 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967268, broadcast_delta=10
2023-01-15 19:35:02.875 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967267, broadcast_delta=10
2023-01-15 19:53:17.141 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967266, broadcast_delta=10
2023-01-15 20:10:55.503 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967265, broadcast_delta=10
2023-01-15 20:18:18.427 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967264, broadcast_delta=10
2023-01-15 20:19:41.056 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967263, broadcast_delta=10
2023-01-15 20:22:49.295 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967262, broadcast_delta=10
2023-01-15 20:25:51.750 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967261, broadcast_delta=10
2023-01-15 20:34:17.277 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967260, broadcast_delta=10
2023-01-15 20:57:52.025 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967259, broadcast_delta=10
2023-01-15 21:02:04.538 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967258, broadcast_delta=10
2023-01-15 21:03:28.162 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967257, broadcast_delta=10
2023-01-15 21:05:09.258 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967256, broadcast_delta=10
2023-01-15 21:07:46.737 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967255, broadcast_delta=10
2023-01-15 21:12:06.863 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967254, broadcast_delta=10
2023-01-15 21:12:14.805 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967253, broadcast_delta=10
2023-01-15 21:19:17.816 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967252, broadcast_delta=10
2023-01-15 21:25:34.685 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967251, broadcast_delta=10
2023-01-15 21:27:56.146 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967250, broadcast_delta=10
2023-01-15 21:30:49.181 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967249, broadcast_delta=10
2023-01-15 21:35:26.541 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967248, broadcast_delta=10
2023-01-15 21:35:51.304 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967247, broadcast_delta=10
2023-01-15 21:44:13.762 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967246, broadcast_delta=10
2023-01-15 21:46:21.760 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967245, broadcast_delta=10
2023-01-15 21:50:47.993 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967244, broadcast_delta=10
2023-01-15 21:51:14.264 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967243, broadcast_delta=10
2023-01-15 22:26:42.823 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967242, broadcast_delta=10
2023-01-15 22:39:27.061 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967241, broadcast_delta=10
2023-01-15 22:39:49.597 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967240, broadcast_delta=10
2023-01-15 22:42:47.587 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967239, broadcast_delta=10
2023-01-15 23:03:09.976 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967238, broadcast_delta=10
2023-01-15 23:04:06.639 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967237, broadcast_delta=10
2023-01-15 23:08:55.801 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967236, broadcast_delta=10
2023-01-15 23:15:32.307 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967235, broadcast_delta=10
2023-01-15 23:26:03.662 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967234, broadcast_delta=10
2023-01-15 23:40:56.350 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967233, broadcast_delta=10
2023-01-15 23:56:43.706 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967232, broadcast_delta=10
2023-01-16 00:19:25.876 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967231, broadcast_delta=10
2023-01-16 00:25:29.719 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967230, broadcast_delta=10
2023-01-16 00:33:31.453 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967229, broadcast_delta=10
2023-01-16 00:50:58.257 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967228, broadcast_delta=10
2023-01-16 00:57:28.544 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967227, broadcast_delta=10
2023-01-16 00:59:20.540 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967226, broadcast_delta=10
2023-01-16 01:05:19.128 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967225, broadcast_delta=10
2023-01-16 01:12:31.246 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967224, broadcast_delta=10
2023-01-16 01:13:42.298 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967223, broadcast_delta=10
2023-01-16 01:24:42.529 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967222, broadcast_delta=10
2023-01-16 01:25:30.139 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967221, broadcast_delta=10
2023-01-16 01:35:22.218 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967220, broadcast_delta=10
2023-01-16 01:52:06.193 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967219, broadcast_delta=10
2023-01-16 01:52:14.357 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967218, broadcast_delta=10
2023-01-16 01:54:48.904 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967217, broadcast_delta=10
2023-01-16 02:19:40.698 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967216, broadcast_delta=10
2023-01-16 02:20:27.787 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967215, broadcast_delta=10
2023-01-16 02:31:48.925 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967214, broadcast_delta=10
2023-01-16 02:47:53.029 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967213, broadcast_delta=10
2023-01-16 02:51:28.911 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967212, broadcast_delta=10
2023-01-16 03:14:15.902 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967211, broadcast_delta=10
2023-01-16 03:19:12.745 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967210, broadcast_delta=10
2023-01-16 03:20:56.993 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967209, broadcast_delta=10
2023-01-16 03:29:23.490 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967208, broadcast_delta=10
2023-01-16 03:40:55.728 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967207, broadcast_delta=10
2023-01-16 03:49:29.578 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967206, broadcast_delta=10
2023-01-16 04:00:16.814 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967205, broadcast_delta=10
2023-01-16 04:03:32.323 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967204, broadcast_delta=10
2023-01-16 04:06:19.468 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967203, broadcast_delta=10
2023-01-16 04:13:27.426 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967202, broadcast_delta=10
2023-01-16 04:21:12.525 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967201, broadcast_delta=10
2023-01-16 04:22:53.999 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967200, broadcast_delta=10
2023-01-16 04:24:53.679 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967199, broadcast_delta=10
2023-01-16 04:39:58.110 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967198, broadcast_delta=10
2023-01-16 05:00:39.462 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967197, broadcast_delta=10
2023-01-16 05:08:05.819 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967196, broadcast_delta=10
2023-01-16 05:19:42.812 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967195, broadcast_delta=10
2023-01-16 05:20:41.309 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967194, broadcast_delta=10
2023-01-16 05:26:38.321 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_REDACTED:0): go to chain for incoming htlc HTLC_ID_REDACTED: timeout=772086, blocks_until_expiry=4294967193, broadcast_delta=10

A possibly related log line around the time the HTLC was initially forwarded:

2023-01-15 01:48:16.130 [ERR] HSWC: Unhandled error while reforwarding htlc settle/fail over htlcswitch: circuit has already been closed

Here's the HTLC in the listchannels output:

            "pending_htlcs": [
                {
                    "incoming": true,
                    "amount": "1",
                    "hash_lock": "HTLC_ID_REDACTED",
                    "expiration_height": 772086,
                    "htlc_index": "REDACTED",
                    "forwarding_channel": "0",
                    "forwarding_htlc_index": "0"
                }
            ],

Your environment

Steps to reproduce

I don't know

Expected behaviour

These htlcs should end up in a final state. Probably either by closing the channel, or by removing the htlc.

Actual behaviour

The htlcs are dangling forever. I don't know which is the oldest one, but at least one of them has expiration height 696312, which was August 2021.

yyforyongyu commented 1 year ago

Could you turn on debug log for CNCT and collect some relevant logs? My suspicion is, since the dust HTLCs are never sent to chain or settled, once timed out, they are left on the commitment forever as we forgot to clean them.

JssDWt commented 1 year ago

Could you turn on debug log for CNCT and collect some relevant logs? My suspicion is, since the dust HTLCs are never sent to chain or settled, once timed out, they are left on the commitment forever as we forgot to clean them.

I think we can do that. How much impact to you think that will have on the amount of logs produced? I looked at the debug statements and it doesn't look too bad at first glance?

yyforyongyu commented 1 year ago

It depends. I think if you turn on debug logging of CNCT for several blocks should be enough to collect the info we need here.

JssDWt commented 1 year ago

@yyforyongyu These are CNCT logs from a specific channelpoint. These logs repeat for every block:

2023-01-31 04:26:30.243 [DBG] CNCT: ChannelArbitrator(CHANNELPOINT_A_REDACTED:0): attempting state step with trigger=chainTrigger from state=StateDefault
2023-01-31 04:26:30.299 [DBG] CNCT: ChannelArbitrator(CHANNELPOINT_A_REDACTED:0): new block (height=774416) examining active HTLC's
2023-01-31 04:26:30.520 [DBG] CNCT: ChannelArbitrator(CHANNELPOINT_A_REDACTED:0): checking commit chain actions at height=774416, in_htlc_count=1, out_htlc_count=0
2023-01-31 04:26:30.723 [INF] CNCT: ChannelArbitrator(CHANNELPOINT_A_REDACTED:0): go to chain for incoming htlc HTLC_ID_A_REDACTED: timeout=659057, blocks_until_expiry=4294851937, broadcast_delta=10
2023-01-31 04:26:31.295 [DBG] CNCT: ChannelArbitrator(CHANNELPOINT_A_REDACTED:0): no resolution needed for incoming dust htlc=HTLC_ID_A_REDACTED
2023-01-31 04:26:31.469 [DBG] CNCT: ChannelArbitrator(CHANNELPOINT_A_REDACTED:0): no actions for chain trigger, terminating
2023-01-31 04:26:31.589 [DBG] CNCT: ChannelArbitrator(CHANNELPOINT_A_REDACTED:0): terminating at state=StateDefault
yyforyongyu commented 1 year ago

@JssDWt thanks for the logs. Yeah we need to clean the dust htlcs, will create a PR.