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.

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

Small payments not going through on mainnet #2718

Closed
TonyGiorgio opened this issue Nov 8, 2023 · 10 comments · Fixed by #2722
Closed

Small payments not going through on mainnet #2718

TonyGiorgio opened this issue Nov 8, 2023 · 10 comments · Fixed by #2722

Comments

@TonyGiorgio
Copy link
Contributor

TonyGiorgio commented Nov 8, 2023

Last time this happened it was due to high mempool congestion, is that's what is going on here again? Hard to tell by the logs. Tested with a 100 sat payment in these logs. I immediately testing 50k sats after and it went through no problem.

255e 2023-11-08 16:20:04.488 DEBUG [mutiny_core::gossip:154] Previous gossip sync timestamp: 0
255e 2023-11-08 16:20:05.306 DEBUG [mutiny_core::gossip:175] retrieved remote scorer
255e 2023-11-08 16:20:06.113 INFO  [mutiny_core::node:200] initializing a new node: cc257f44-89b9-405c-9a74-e09ac2b86646
255e 2023-11-08 16:20:06.198 DEBUG [mutiny_core::ldkstorage:209] Reading channel manager from storage
255e 2023-11-08 16:20:06.244 INFO  [lightning::ln::channelmanager:10006] Successfully loaded channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a at update_id 5474 against monitor at update id 5474
255e 2023-11-08 16:20:06.246 INFO  [lightning::ln::channelmanager:10006] Successfully loaded channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb at update_id 494 against monitor at update id 494
255e 2023-11-08 16:20:06.247 INFO  [mutiny_core::node:322] creating lsp client
255e 2023-11-08 16:20:06.248 TRACE [lightning::chain::chainmonitor:722] Got new ChannelMonitor for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:06.251 INFO  [lightning::chain::chainmonitor:728] Persistence of new ChannelMonitor for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a in progress
255e 2023-11-08 16:20:06.251 TRACE [lightning::chain::chainmonitor:722] Got new ChannelMonitor for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:06.251 INFO  [lightning::chain::chainmonitor:728] Persistence of new ChannelMonitor for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb in progress
255e 2023-11-08 16:20:06.251 INFO  [mutiny_core::node:564] Node started: 03818a6060cb899d52258a7c12c57e754b625391e2fea1f81d3c2b221e0ecb7222
255e 2023-11-08 16:20:06.252 INFO  [mutiny_core::nodemanager:749] inserting updated nodes
255e 2023-11-08 16:20:06.252 INFO  [mutiny_core::nodemanager:756] inserted updated nodes
255e 2023-11-08 16:20:06.258 TRACE [mutiny_core::background:557] Calling ChannelManager's timer_tick_occurred on startup
255e 2023-11-08 16:20:06.259 TRACE [mutiny_core::fees:174] Got fee rate from saved cache!
255e 2023-11-08 16:20:06.259 TRACE [mutiny_core::fees:174] Got fee rate from saved cache!
255e 2023-11-08 16:20:06.259 TRACE [lightning::ln::channelmanager:4795] Channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a does not qualify for a feerate change from 23500 to 22250.
255e 2023-11-08 16:20:06.259 TRACE [lightning::ln::channelmanager:4795] Channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb does not qualify for a feerate change from 23500 to 22250.
255e 2023-11-08 16:20:06.259 TRACE [mutiny_core::background:557] Rebroadcasting monitor's pending claims on startup
255e 2023-11-08 16:20:06.264 INFO  [mutiny_core::nodemanager:1477] RGS URL: https://scorer.mutinywallet.com/v1/rgs/snapshot/0
255e 2023-11-08 16:20:06.929 TRACE [mutiny_core::fees:125] Retrieved fees from mempool
255e 2023-11-08 16:20:07.479 DEBUG [mutiny_core::ldkstorage:121] Persisted channel monitor: MonitorUpdateIdentifier { funding_txo: OutPoint { txid: eb5aa8d919a54fa166f41f32db60d54ac9d9286ffdba2c9a3380f1fa880f1d76, index: 0 }, monitor_update_id: MonitorUpdateId { contents: OffChain(494) } }
255e 2023-11-08 16:20:07.480 TRACE [lightning::ln::channelmanager:5910] ChannelMonitor updated to 494. Current highest is 494. 0 pending in-flight updates.
255e 2023-11-08 16:20:07.480 TRACE [mutiny_core::background:557] Persisting ChannelManager...
255e 2023-11-08 16:20:07.489 TRACE [mutiny_core::background:557] Done persisting ChannelManager.
255e 2023-11-08 16:20:07.937 DEBUG [mutiny_core::networking::proxy:69] connected to ws: wss://p.mutinywallet.com
255e 2023-11-08 16:20:07.944 DEBUG [mutiny_core::peermanager:433] connected to peer: PubkeyConnectionInfo { pubkey: PublicKey(f0e18eca0f86800041211951fbbbabdbb7743995059d12a4219b00b4fb43faaec9a0af987303533cdaa9a57b32494716c973a7a53696dd46367cb483a5fa46e6), connection_type: Tcp("52.88.33.119:9735"), original_connection_string: "03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0@52.88.33.119:9735" }
255e 2023-11-08 16:20:07.945 TRACE [mutiny_core::peermanager:436] sent 50 to node: 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0
255e 2023-11-08 16:20:07.945 TRACE [mutiny_core::networking::socket:65] scheduling descriptor reader
255e 2023-11-08 16:20:07.945 TRACE [mutiny_core::node:1729] auto connected lsp: 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0
255e 2023-11-08 16:20:07.946 TRACE [mutiny_core::networking::proxy:92] sent data down websocket
255e 2023-11-08 16:20:07.951 DEBUG [mutiny_core::ldkstorage:121] Persisted channel monitor: MonitorUpdateIdentifier { funding_txo: OutPoint { txid: 5b1e1c1d82c243e6260c610f487000fd535f1a0e16d6c86ce1519ca3be2ce2b3, index: 1 }, monitor_update_id: MonitorUpdateId { contents: OffChain(5474) } }
255e 2023-11-08 16:20:07.951 TRACE [lightning::ln::channelmanager:5910] ChannelMonitor updated to 5474. Current highest is 5474. 0 pending in-flight updates.
255e 2023-11-08 16:20:07.952 TRACE [mutiny_core::background:557] Persisting ChannelManager...
255e 2023-11-08 16:20:07.953 TRACE [mutiny_core::background:557] Done persisting ChannelManager.
255e 2023-11-08 16:20:08.062 TRACE [mutiny_core::networking::socket:77] received binary data from websocket
255e 2023-11-08 16:20:08.093 DEBUG [lightning::ln::peer_handler:1374] Finished noise handshake for connection with 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0
255e 2023-11-08 16:20:08.094 TRACE [lightning::ln::peer_handler:1240] Enqueueing message Init { features: [33, 81, 138, 8, 128, 160, 8], networks: Some([6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000]), remote_network_address: Some(TcpIpV4 { addr: [52, 88, 33, 119], port: 9735 }) } to 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0
255e 2023-11-08 16:20:08.094 TRACE [mutiny_core::networking::proxy:92] sent data down websocket
255e 2023-11-08 16:20:08.094 TRACE [mutiny_core::networking::proxy:92] sent data down websocket
255e 2023-11-08 16:20:08.205 TRACE [mutiny_core::networking::socket:77] received binary data from websocket
255e 2023-11-08 16:20:08.205 INFO  [lightning::ln::peer_handler:1539] Received peer Init message from 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0: DataLossProtect: supported, InitialRoutingSync: not supported, UpfrontShutdownScript: supported, GossipQueries: supported, VariableLengthOnion: required, StaticRemoteKey: supported, PaymentSecret: required, BasicMPP: supported, Wumbo: supported, AnchorsNonzeroFeeHtlcTx: not supported, AnchorsZeroFeeHtlcTx: not supported, ShutdownAnySegwit: supported, Taproot: not supported, OnionMessages: not supported, ChannelType: supported, SCIDPrivacy: supported, ZeroConf: supported, unknown flags: supported
255e 2023-11-08 16:20:08.205 DEBUG [lightning::ln::channelmanager:8721] Generating channel_reestablish events for 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0
255e 2023-11-08 16:20:08.206 TRACE [lightning::ln::channel:5237] Enough info to generate a Data Loss Protect with per_commitment_secret 83902895c00c231b323cf6a1145e30e19d2a1872e9246168472ab78d225900cb for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:08.206 TRACE [lightning::ln::channel:5237] Enough info to generate a Data Loss Protect with per_commitment_secret 08003a0726d9db9503910e9ebccd0485501d96d45a50db0c1a097be38c6916ca for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:08.206 DEBUG [lightning::ln::peer_handler:2067] Handling SendChannelReestablish event in peer_handler for node 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0 for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:08.206 TRACE [lightning::ln::peer_handler:1240] Enqueueing message ChannelReestablish { channel_id: ChannelId([179, 226, 44, 190, 163, 156, 81, 225, 108, 200, 214, 22, 14, 26, 95, 83, 253, 0, 112, 72, 15, 97, 12, 38, 230, 67, 194, 130, 29, 28, 30, 90]), next_local_commitment_number: 2274, next_remote_commitment_number: 2272, your_last_per_commitment_secret: [131, 144, 40, 149, 192, 12, 35, 27, 50, 60, 246, 161, 20, 94, 48, 225, 157, 42, 24, 114, 233, 36, 97, 104, 71, 42, 183, 141, 34, 89, 0, 203], my_current_per_commitment_point: PublicKey(02020202020202020202020202020202020202020202020202020202020202ffcee50f772e0a9972250d4b61b3e5beb95de897c73b4ed1cc35ed013accf1c840), next_funding_txid: None } to 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0
255e 2023-11-08 16:20:08.206 DEBUG [lightning::ln::peer_handler:2067] Handling SendChannelReestablish event in peer_handler for node 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0 for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:08.207 TRACE [lightning::ln::peer_handler:1240] Enqueueing message ChannelReestablish { channel_id: ChannelId([118, 29, 15, 136, 250, 241, 128, 51, 154, 44, 186, 253, 111, 40, 217, 201, 74, 213, 96, 219, 50, 31, 244, 102, 161, 79, 165, 25, 217, 168, 90, 235]), next_local_commitment_number: 202, next_remote_commitment_number: 201, your_last_per_commitment_secret: [8, 0, 58, 7, 38, 217, 219, 149, 3, 145, 14, 158, 188, 205, 4, 133, 80, 29, 150, 212, 90, 80, 219, 12, 26, 9, 123, 227, 140, 105, 22, 202], my_current_per_commitment_point: PublicKey(02020202020202020202020202020202020202020202020202020202020202ffcee50f772e0a9972250d4b61b3e5beb95de897c73b4ed1cc35ed013accf1c840), next_funding_txid: None } to 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0
255e 2023-11-08 16:20:08.207 TRACE [mutiny_core::networking::proxy:92] sent data down websocket
255e 2023-11-08 16:20:08.207 TRACE [mutiny_core::networking::proxy:92] sent data down websocket
255e 2023-11-08 16:20:08.264 TRACE [mutiny_core::networking::socket:77] received binary data from websocket
255e 2023-11-08 16:20:08.264 DEBUG [lightning::ln::channelmanager:6973] Received channel_update ChannelUpdate { signature: 304402204ba67b5680457a0f85b707e601c6e0ca075972e9e3718e2e86b1e88efbb7002f02207d74448fb51178e7853f1f2f69377286f56de1e1e9db802fcebe8e16bb559ae0, contents: UnsignedChannelUpdate { chain_hash: 6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000, short_channel_id: 895805108656537600, timestamp: 1699459988, flags: 1, cltv_expiry_delta: 34, htlc_minimum_msat: 1, htlc_maximum_msat: 990000000, fee_base_msat: 1000, fee_proportional_millionths: 10, excess_data: [] } } for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb.
255e 2023-11-08 16:20:08.264 DEBUG [lightning::ln::peer_handler:1472] Error handling message from 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0; ignoring: Couldn't find channel for update
255e 2023-11-08 16:20:08.265 TRACE [mutiny_core::networking::socket:77] received binary data from websocket
255e 2023-11-08 16:20:08.265 DEBUG [lightning::ln::channelmanager:6973] Received channel_update ChannelUpdate { signature: 3044022040b7bf70e0f91c5d03fb4eda5ef385696968febd8f2aef26ad6f92fb7cf8ef2c02200ceb3982231f4c8150a2afcd0a7b69f91516901295207958bef333c6fd17160a, contents: UnsignedChannelUpdate { chain_hash: 6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000, short_channel_id: 882907837178052609, timestamp: 1699459989, flags: 1, cltv_expiry_delta: 34, htlc_minimum_msat: 1, htlc_maximum_msat: 1980000000, fee_base_msat: 1000, fee_proportional_millionths: 10, excess_data: [] } } for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a.
255e 2023-11-08 16:20:08.265 DEBUG [lightning::ln::peer_handler:1472] Error handling message from 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0; ignoring: Couldn't find channel for update
255e 2023-11-08 16:20:08.265 DEBUG [lightning::ln::peer_handler:1472] Error handling message from 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0; ignoring: Couldn't find channel for update
255e 2023-11-08 16:20:08.269 TRACE [mutiny_core::networking::socket:77] received binary data from websocket
255e 2023-11-08 16:20:08.277 TRACE [mutiny_core::networking::socket:77] received binary data from websocket
255e 2023-11-08 16:20:08.307 TRACE [mutiny_core::networking::socket:77] received binary data from websocket
255e 2023-11-08 16:20:08.393 TRACE [mutiny_core::networking::socket:77] received binary data from websocket
255e 2023-11-08 16:20:08.393 TRACE [lightning::ln::peer_handler:1586] Received message ChannelReestablish(ChannelReestablish { channel_id: ChannelId([179, 226, 44, 190, 163, 156, 81, 225, 108, 200, 214, 22, 14, 26, 95, 83, 253, 0, 112, 72, 15, 97, 12, 38, 230, 67, 194, 130, 29, 28, 30, 90]), next_local_commitment_number: 2273, next_remote_commitment_number: 2273, your_last_per_commitment_secret: [59, 16, 6, 75, 145, 31, 67, 184, 228, 39, 73, 26, 21, 89, 227, 178, 67, 185, 48, 87, 135, 244, 26, 148, 180, 183, 64, 53, 39, 219, 203, 17], my_current_per_commitment_point: PublicKey(9ae83f096fca5bd18ceabbc522fd57e58f13e6f083fd52574c3531c9fba445a5661eeb3a7a78c7b077b9702d376d24e345f7806d18e9bf8c2ea3be5039aa6503), next_funding_txid: None }) from 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0
255e 2023-11-08 16:20:08.394 TRACE [lightning::ln::channel:5102] Creating an announcement_signatures message for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:08.394 TRACE [lightning::ln::channel:5106] Ignore : Channel is not available for public announcements
255e 2023-11-08 16:20:08.394 DEBUG [lightning::ln::channel:4124] Reconnected channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a with no loss
255e 2023-11-08 16:20:08.394 TRACE [lightning::ln::channelmanager:3356] Attempting to generate channel update for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:08.394 TRACE [lightning::ln::channelmanager:3366] Generating channel update for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:08.395 TRACE [lightning::ln::channelmanager:5806] Handling channel resumption for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a with no RAA, no commitment update, 0 pending forwards, not broadcasting funding, without channel ready, without announcement
255e 2023-11-08 16:20:08.395 TRACE [lightning::ln::peer_handler:1586] Received message ChannelReestablish(ChannelReestablish { channel_id: ChannelId([118, 29, 15, 136, 250, 241, 128, 51, 154, 44, 186, 253, 111, 40, 217, 201, 74, 213, 96, 219, 50, 31, 244, 102, 161, 79, 165, 25, 217, 168, 90, 235]), next_local_commitment_number: 202, next_remote_commitment_number: 201, your_last_per_commitment_secret: [198, 200, 49, 238, 70, 83, 252, 247, 249, 105, 116, 140, 114, 72, 61, 153, 22, 111, 139, 53, 57, 225, 237, 65, 255, 237, 113, 35, 242, 167, 72, 23], my_current_per_commitment_point: PublicKey(e4c68953b8213babdf490c7ebec32e67f74ab5ba856b79c63c08cdf34ea1f847c62afba08e6fb768f04c38bcdb4097f5c5d38876e870be597127de305c6378ba), next_funding_txid: None }) from 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0
255e 2023-11-08 16:20:08.396 TRACE [lightning::ln::channel:5102] Creating an announcement_signatures message for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:08.396 TRACE [lightning::ln::channel:5106] Ignore : Channel is not available for public announcements
255e 2023-11-08 16:20:08.396 DEBUG [lightning::ln::channel:4124] Reconnected channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb with no loss
255e 2023-11-08 16:20:08.396 TRACE [lightning::ln::channelmanager:3356] Attempting to generate channel update for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:08.396 TRACE [lightning::ln::channelmanager:3366] Generating channel update for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:08.397 TRACE [lightning::ln::channelmanager:5806] Handling channel resumption for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb with no RAA, no commitment update, 0 pending forwards, not broadcasting funding, without channel ready, without announcement
255e 2023-11-08 16:20:08.397 TRACE [lightning::ln::peer_handler:2111] Handling SendChannelUpdate event in peer_handler for node 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0 for channel 882907837178052609
255e 2023-11-08 16:20:08.397 TRACE [lightning::ln::peer_handler:2111] Handling SendChannelUpdate event in peer_handler for node 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0 for channel 895805108656537600
255e 2023-11-08 16:20:08.397 TRACE [mutiny_core::networking::proxy:92] sent data down websocket
255e 2023-11-08 16:20:08.397 TRACE [mutiny_core::networking::proxy:92] sent data down websocket
255e 2023-11-08 16:20:08.556 TRACE [lightning_rapid_gossip_sync::processing:62] Processing RGS data...
255e 2023-11-08 16:20:08.922 DEBUG [lightning_rapid_gossip_sync::processing:148] Processing RGS update from 1699459200 with 8329 nodes, 52532 channel announcements and 104823 channel updates.
255e 2023-11-08 16:20:09.638 TRACE [lightning_rapid_gossip_sync::processing:257] Done processing RGS data from 1699459200
255e 2023-11-08 16:20:09.638 INFO  [mutiny_core::gossip:233] RGS sync result: 1699459200
255e 2023-11-08 16:20:09.638 INFO  [mutiny_core::nodemanager:949] RGS Synced!
255e 2023-11-08 16:20:09.638 INFO  [mutiny_core::nodemanager:958] Updated fee estimates!
255e 2023-11-08 16:20:09.639 INFO  [mutiny_core::esplora:221] Starting transaction sync.
255e 2023-11-08 16:20:09.640 TRACE [mutiny_core::background:557] Persisting network graph.
255e 2023-11-08 16:20:10.496 TRACE [lightning::ln::channelmanager:8074] New best block: 000000000000000000002ea2808bc01b1e46e7ae4795c052b0571a0c83d12165 at height 815881
255e 2023-11-08 16:20:10.497 TRACE [lightning::ln::channel:5102] Creating an announcement_signatures message for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:10.497 TRACE [lightning::ln::channel:5106] Ignore : Channel is not available for public announcements
255e 2023-11-08 16:20:10.497 TRACE [lightning::ln::channel:5102] Creating an announcement_signatures message for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:10.497 TRACE [lightning::ln::channel:5106] Ignore : Channel is not available for public announcements
255e 2023-11-08 16:20:10.497 DEBUG [lightning::chain::chainmonitor:682] New best block 000000000000000000002ea2808bc01b1e46e7ae4795c052b0571a0c83d12165 at height 815881 provided via best_block_updated
255e 2023-11-08 16:20:10.498 TRACE [lightning::chain::channelmonitor:3567] Processing 0 matched transactions for block at height 815881.
255e 2023-11-08 16:20:10.498 DEBUG [lightning::chain::onchaintx:699] Updating claims view at height 815881 with 0 claim requests
255e 2023-11-08 16:20:10.499 DEBUG [lightning::chain::onchaintx:820] Updating claims view at height 815881 with 0 matched transactions in block 815881
255e 2023-11-08 16:20:10.499 TRACE [lightning::chain::onchaintx:951] Bumping 0 candidates
255e 2023-11-08 16:20:10.499 TRACE [lightning::chain::chainmonitor:378] Syncing Channel Monitor for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:10.500 DEBUG [lightning::chain::chainmonitor:383] Channel Monitor sync for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a in progress, holding events until completion!
255e 2023-11-08 16:20:10.500 TRACE [lightning::chain::channelmonitor:3567] Processing 0 matched transactions for block at height 815881.
255e 2023-11-08 16:20:10.500 DEBUG [lightning::chain::onchaintx:699] Updating claims view at height 815881 with 0 claim requests
255e 2023-11-08 16:20:10.500 DEBUG [lightning::chain::onchaintx:820] Updating claims view at height 815881 with 0 matched transactions in block 815881
255e 2023-11-08 16:20:10.500 TRACE [lightning::chain::onchaintx:951] Bumping 0 candidates
255e 2023-11-08 16:20:10.500 TRACE [lightning::chain::chainmonitor:378] Syncing Channel Monitor for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:10.500 DEBUG [lightning::chain::chainmonitor:383] Channel Monitor sync for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb in progress, holding events until completion!
255e 2023-11-08 16:20:10.501 TRACE [mutiny_core::background:557] Persisting ChannelManager...
255e 2023-11-08 16:20:10.502 TRACE [mutiny_core::background:557] Done persisting ChannelManager.
255e 2023-11-08 16:20:10.502 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:10.503 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:10.503 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:10.503 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:10.721 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:10.721 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:10.721 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:10.721 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:10.802 TRACE [lightning::ln::channelmanager:8053] 1 transactions included in block 000000000000000000026d15f33764be84855e32d8ea6d73efa4c0a521b1976a at height 803000 provided
255e 2023-11-08 16:20:10.802 TRACE [lightning::ln::channel:5102] Creating an announcement_signatures message for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:10.802 TRACE [lightning::ln::channel:5106] Ignore : Channel is not available for public announcements
255e 2023-11-08 16:20:10.802 TRACE [lightning::ln::channel:5102] Creating an announcement_signatures message for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:10.802 TRACE [lightning::ln::channel:5106] Ignore : Channel is not available for public announcements
255e 2023-11-08 16:20:10.802 DEBUG [lightning::chain::chainmonitor:666] 1 provided transactions confirmed at height 803000 in block 000000000000000000026d15f33764be84855e32d8ea6d73efa4c0a521b1976a
255e 2023-11-08 16:20:10.804 TRACE [lightning::chain::channelmonitor:3567] Processing 0 matched transactions for block at height 803000.
255e 2023-11-08 16:20:10.804 DEBUG [lightning::chain::onchaintx:699] Updating claims view at height 815881 with 0 claim requests
255e 2023-11-08 16:20:10.804 DEBUG [lightning::chain::onchaintx:820] Updating claims view at height 815881 with 0 matched transactions in block 803000
255e 2023-11-08 16:20:10.804 TRACE [lightning::chain::onchaintx:951] Bumping 0 candidates
255e 2023-11-08 16:20:10.804 TRACE [lightning::chain::chainmonitor:378] Syncing Channel Monitor for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:10.805 DEBUG [lightning::chain::chainmonitor:383] Channel Monitor sync for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a in progress, holding events until completion!
255e 2023-11-08 16:20:10.805 TRACE [lightning::chain::channelmonitor:3567] Processing 0 matched transactions for block at height 803000.
255e 2023-11-08 16:20:10.805 DEBUG [lightning::chain::onchaintx:699] Updating claims view at height 815881 with 0 claim requests
255e 2023-11-08 16:20:10.805 DEBUG [lightning::chain::onchaintx:820] Updating claims view at height 815881 with 0 matched transactions in block 803000
255e 2023-11-08 16:20:10.805 TRACE [lightning::chain::onchaintx:951] Bumping 0 candidates
255e 2023-11-08 16:20:10.805 TRACE [lightning::chain::chainmonitor:378] Syncing Channel Monitor for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:10.805 DEBUG [lightning::chain::chainmonitor:383] Channel Monitor sync for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb in progress, holding events until completion!
255e 2023-11-08 16:20:10.805 TRACE [lightning::ln::channelmanager:8053] 1 transactions included in block 00000000000000000000d363933717f6006c141855fe8142f8b2658b7d34f468 at height 814730 provided
255e 2023-11-08 16:20:10.805 TRACE [lightning::ln::channel:5102] Creating an announcement_signatures message for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a
255e 2023-11-08 16:20:10.805 TRACE [lightning::ln::channel:5106] Ignore : Channel is not available for public announcements
255e 2023-11-08 16:20:10.805 TRACE [lightning::ln::channel:5102] Creating an announcement_signatures message for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb
255e 2023-11-08 16:20:10.805 TRACE [lightning::ln::channel:5106] Ignore : Channel is not available for public announcements
255e 2023-11-08 16:20:10.805 DEBUG [lightning::chain::chainmonitor:666] 1 provided transactions confirmed at height 814730 in block 00000000000000000000d363933717f6006c141855fe8142f8b2658b7d34f468
255e 2023-11-08 16:20:10.805 TRACE [lightning::chain::channelmonitor:3567] Processing 0 matched transactions for block at height 814730.
255e 2023-11-08 16:20:10.805 DEBUG [lightning::chain::onchaintx:699] Updating claims view at height 815881 with 0 claim requests
255e 2023-11-08 16:20:10.805 DEBUG [lightning::chain::onchaintx:820] Updating claims view at height 815881 with 0 matched transactions in block 814730
...
255e 2023-11-08 16:20:13.351 TRACE [mutiny_core::networking::socket:77] received binary data from websocket
255e 2023-11-08 16:20:13.351 DEBUG [lightning::ln::channelmanager:6973] Received channel_update ChannelUpdate { signature: 304402205d4ac55b4a7abf11ae5016b79bb52dbda6fdf5835858ddc51fe87e4ab618daf9022016020cbc1a57e5c988ed261f85777ef14b4a16e432ebc31433b552e3ddd54350, contents: UnsignedChannelUpdate { chain_hash: 6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000, short_channel_id: 882907837178052609, timestamp: 1699460114, flags: 1, cltv_expiry_delta: 34, htlc_minimum_msat: 1, htlc_maximum_msat: 1980000000, fee_base_msat: 1000, fee_proportional_millionths: 10, excess_data: [] } } for channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a.
255e 2023-11-08 16:20:13.351 DEBUG [lightning::ln::peer_handler:1472] Error handling message from 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0; ignoring: Couldn't find channel for update
255e 2023-11-08 16:20:13.351 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:13.354 DEBUG [mutiny_core::ldkstorage:121] Persisted channel monitor: MonitorUpdateIdentifier { funding_txo: OutPoint { txid: 5b1e1c1d82c243e6260c610f487000fd535f1a0e16d6c86ce1519ca3be2ce2b3, index: 1 }, monitor_update_id: MonitorUpdateId { contents: ChainSync(4294967298) } }
255e 2023-11-08 16:20:13.354 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:13.354 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:13.412 TRACE [mutiny_core::networking::socket:77] received binary data from websocket
255e 2023-11-08 16:20:13.412 DEBUG [lightning::ln::channelmanager:6973] Received channel_update ChannelUpdate { signature: 3044022060ae7ed835100490c3557a4134f7ec0928600d67e3b649813daa8df42403228502200d4797cd56245272079a079e85d14960aaa150aeeddf9dc90b13710379faf425, contents: UnsignedChannelUpdate { chain_hash: 6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000, short_channel_id: 895805108656537600, timestamp: 1699460113, flags: 1, cltv_expiry_delta: 34, htlc_minimum_msat: 1, htlc_maximum_msat: 990000000, fee_base_msat: 1000, fee_proportional_millionths: 10, excess_data: [] } } for channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb.
255e 2023-11-08 16:20:13.412 DEBUG [lightning::ln::peer_handler:1472] Error handling message from 03aefa43fbb4009b21a4129d05953974b7dbabbbfb511921410080860fca8ee1f0; ignoring: Couldn't find channel for update
255e 2023-11-08 16:20:13.413 DEBUG [lightning::chain::chainmonitor:821] A Channel Monitor sync is still in progress, refusing to provide monitor events!
255e 2023-11-08 16:20:13.421 INFO  [mutiny_core::nodemanager:1519] We are synced!
...
255e 2023-11-08 16:21:06.598 TRACE [lightning::ln::channelmanager:4795] Channel b3e22cbea39c51e16cc8d6160e1a5f53fd0070480f610c26e643c2821d1c1e5a does not qualify for a feerate change from 23500 to 18500.
255e 2023-11-08 16:21:06.598 TRACE [lightning::ln::channelmanager:4795] Channel 761d0f88faf180339a2cbafd6f28d9c94ad560db321ff466a14fa519d9a85aeb does not qualify for a feerate change from 23500 to 18500.
255e 2023-11-08 16:21:07.460 TRACE [mutiny_core::ldkstorage:378] Trace: checking payment key: payment_outbound/c0e4f9038d3bfeb9cc119f489b754229946b80d08f3dce01da918a637c2fb8db_cc257f44-89b9-405c-9a74-e09ac2b86646
255e 2023-11-08 16:21:07.460 TRACE [mutiny_core::ldkstorage:378] Trace: checking payment key: payment_inbound/c0e4f9038d3bfeb9cc119f489b754229946b80d08f3dce01da918a637c2fb8db_cc257f44-89b9-405c-9a74-e09ac2b86646
255e 2023-11-08 16:21:07.469 TRACE [lightning::routing::router:1623] Searching for a route from payer 03818a6060cb899d52258a7c12c57e754b625391e2fea1f81d3c2b221e0ecb7222 to payee node id 03cc1d0932bb99b0697f5b5e5961b83ab7fd66f1efc4c9f5c7bad66c1bcbe78f02 with MPP and 2 first hops overriding the network graph with a fee limit of 60000 msat
255e 2023-11-08 16:21:07.470 TRACE [lightning::routing::router:1712] Building path from payee node id 03cc1d0932bb99b0697f5b5e5961b83ab7fd66f1efc4c9f5c7bad66c1bcbe78f02 to payer 03818a6060cb899d52258a7c12c57e754b625391e2fea1f81d3c2b221e0ecb7222 for value 1000000 msat.
255e 2023-11-08 16:21:07.472 TRACE [lightning::routing::router:2286] Starting main path collection loop with 90 nodes pre-filled from first/last hops.
255e 2023-11-08 16:21:07.571 TRACE [lightning::routing::router:2433] Ignoring first hop with SCID 882907837178052609 due to its htlc_minimum_msat limit.
255e 2023-11-08 16:21:07.571 TRACE [lightning::routing::router:2433] Ignoring first hop with SCID 895805108656537600 due to its htlc_minimum_msat limit.
255e 2023-11-08 16:21:07.654 TRACE [lightning::routing::router:2286] Starting main path collection loop with 90 nodes pre-filled from first/last hops.
255e 2023-11-08 16:21:07.703 TRACE [lightning::routing::router:2433] Ignoring first hop with SCID 882907837178052609 due to its htlc_minimum_msat limit.
255e 2023-11-08 16:21:07.703 TRACE [lightning::routing::router:2433] Ignoring first hop with SCID 895805108656537600 due to its htlc_minimum_msat limit.
255e 2023-11-08 16:21:07.783 TRACE [lightning::routing::router:2457] Failed to collect enough value, but running again to collect extra paths with a potentially higher limit.
255e 2023-11-08 16:21:07.784 TRACE [lightning::routing::router:2286] Starting main path collection loop with 90 nodes pre-filled from first/last hops.
255e 2023-11-08 16:21:07.825 TRACE [lightning::routing::router:2433] Ignoring first hop with SCID 882907837178052609 due to its htlc_minimum_msat limit.
255e 2023-11-08 16:21:07.825 TRACE [lightning::routing::router:2433] Ignoring first hop with SCID 895805108656537600 due to its htlc_minimum_msat limit.
255e 2023-11-08 16:21:07.914 TRACE [lightning::routing::router:2460] Have now collected 0 msat (seeking 3000000 msat) in paths. Last path loop did not find a new path.
255e 2023-11-08 16:21:07.914 TRACE [lightning::routing::router:2483] Ignored 510 candidate hops due to insufficient value contribution, 0 due to path length limit, 323 due to CLTV delta limit, 0 due to previous payment failure, 1746 due to htlc_minimum_msat limit, 214 to avoid overpaying, 4309 due to maximum total fee limit. Total: 7102 ignored candidates.
255e 2023-11-08 16:21:07.914 ERROR [lightning::ln::outbound_payment:910] Failed to find route for payment with id c0e4f9038d3bfeb9cc119f489b754229946b80d08f3dce01da918a637c2fb8db and hash c0e4f9038d3bfeb9cc119f489b754229946b80d08f3dce01da918a637c2fb8db
255e 2023-11-08 16:21:07.954 ERROR [mutiny_core::node:1158] failed to make payment: Sending(RouteNotFound)
255e 2023-11-08 16:21:07.955 DEBUG [mutiny_core::node:1161] current channel details: [ChannelDetails { channel_id: ChannelId([179, 226, 44, 190, 163, 156, 81, 225, 108, 200, 214, 22, 14, 26, 95, 83, 253, 0, 112, 72, 15, 97, 12, 38, 230, 67, 194, 130, 29, 28, 30, 90]), counterparty: ChannelCounterparty { node_id: PublicKey(f0e18eca0f86800041211951fbbbabdbb7743995059d12a4219b00b4fb43faaec9a0af987303533cdaa9a57b32494716c973a7a53696dd46367cb483a5fa46e6), features: [162, 105, 10, 10, 0, 160, 8], unspendable_punishment_reserve: 20000, forwarding_info: Some(CounterpartyForwardingInfo { fee_base_msat: 1000, fee_proportional_millionths: 10, cltv_expiry_delta: 34 }), outbound_htlc_minimum_msat: Some(0), outbound_htlc_maximum_msat: Some(1960000000) }, funding_txo: Some(OutPoint { txid: 5b1e1c1d82c243e6260c610f487000fd535f1a0e16d6c86ce1519ca3be2ce2b3, index: 1 }), channel_type: Some([0, 16]), short_channel_id: Some(882907837178052609), outbound_scid_alias: Some(589786833344397314), inbound_scid_alias: None, channel_value_satoshis: 2000000, unspendable_punishment_reserve: Some(20000), user_channel_id: 249229645327869497816677360056284350486, feerate_sat_per_1000_weight: Some(23500), balance_msat: 359454101, outbound_capacity_msat: 339454101, next_outbound_htlc_limit_msat: 289258101, next_outbound_htlc_minimum_msat: 21196000, inbound_capacity_msat: 1620545899, confirmations_required: Some(3), confirmations: Some(12882), force_close_spend_delay: Some(144), is_outbound: true, is_channel_ready: true, channel_shutdown_state: Some(NotShuttingDown), is_usable: true, is_public: false, inbound_htlc_minimum_msat: Some(1), inbound_htlc_maximum_msat: Some(1960000000), config: Some(ChannelConfig { forwarding_fee_proportional_millionths: 0, forwarding_fee_base_msat: 1000, cltv_expiry_delta: 72, max_dust_htlc_exposure: FixedLimitMsat(20000000), force_close_avoidance_max_fee_satoshis: 1000, accept_underpaying_htlcs: false }) }, ChannelDetails { channel_id: ChannelId([118, 29, 15, 136, 250, 241, 128, 51, 154, 44, 186, 253, 111, 40, 217, 201, 74, 213, 96, 219, 50, 31, 244, 102, 161, 79, 165, 25, 217, 168, 90, 235]), counterparty: ChannelCounterparty { node_id: PublicKey(f0e18eca0f86800041211951fbbbabdbb7743995059d12a4219b00b4fb43faaec9a0af987303533cdaa9a57b32494716c973a7a53696dd46367cb483a5fa46e6), features: [162, 105, 10, 10, 0, 160, 8], unspendable_punishment_reserve: 10000, forwarding_info: Some(CounterpartyForwardingInfo { fee_base_msat: 1000, fee_proportional_millionths: 10, cltv_expiry_delta: 34 }), outbound_htlc_minimum_msat: Some(0), outbound_htlc_maximum_msat: Some(980000000) }, funding_txo: Some(OutPoint { txid: eb5aa8d919a54fa166f41f32db60d54ac9d9286ffdba2c9a3380f1fa880f1d76, index: 0 }), channel_type: Some([0, 16]), short_channel_id: Some(895805108656537600), outbound_scid_alias: Some(837665132751028224), inbound_scid_alias: None, channel_value_satoshis: 1000000, unspendable_punishment_reserve: Some(10000), user_channel_id: 119403029337559860442125695504218248759, feerate_sat_per_1000_weight: Some(23500), balance_msat: 504471097, outbound_capacity_msat: 494471097, next_outbound_htlc_limit_msat: 444275097, next_outbound_htlc_minimum_msat: 21196000, inbound_capacity_msat: 485528903, confirmations_required: Some(3), confirmations: Some(1152), force_close_spend_delay: Some(144), is_outbound: true, is_channel_ready: true, channel_shutdown_state: Some(NotShuttingDown), is_usable: true, is_public: false, inbound_htlc_minimum_msat: Some(1), inbound_htlc_maximum_msat: Some(980000000), config: Some(ChannelConfig { forwarding_fee_proportional_millionths: 0, forwarding_fee_base_msat: 1000, cltv_expiry_delta: 72, max_dust_htlc_exposure: FixedLimitMsat(20000000), force_close_avoidance_max_fee_satoshis: 1000, accept_underpaying_htlcs: false }) }]

I pulled out the last line that prints out the channel info in a human readable format. Perhaps something is going on here?

255e 2023-11-08 16:21:07.955 DEBUG [mutiny_core::node:1161] 
current channel details: 

[
    ChannelDetails {
        channel_id: ChannelId([
            179, 226, 44, 190, 163, 156, 81, 225, 108, 200, 214, 22, 
            14, 26, 95, 83, 253, 0, 112, 72, 15, 97, 12, 38, 230, 67, 
            194, 130, 29, 28, 30, 90
        ]),
        counterparty: ChannelCounterparty {
            node_id: PublicKey(
                f0e18eca0f86800041211951fbbbabdbb7743995059d12a4219b00b4fb43faaec9a0af987303533c
                daa9a57b32494716c973a7a53696dd46367cb483a5fa46e6
            ),
            features: [162, 105, 10, 10, 0, 160, 8],
            unspendable_punishment_reserve: 20000,
            forwarding_info: Some(CounterpartyForwardingInfo {
                fee_base_msat: 1000,
                fee_proportional_millionths: 10,
                cltv_expiry_delta: 34
            }),
            outbound_htlc_minimum_msat: Some(0),
            outbound_htlc_maximum_msat: Some(1960000000)
        },
        funding_txo: Some(OutPoint {
            txid: 5b1e1c1d82c243e6260c610f487000fd535f1a0e16d6c86ce1519ca3be2ce2b3,
            index: 1
        }),
        channel_type: Some([0, 16]),
        short_channel_id: Some(882907837178052609),
        outbound_scid_alias: Some(589786833344397314),
        inbound_scid_alias: None,
        channel_value_satoshis: 2000000,
        unspendable_punishment_reserve: Some(20000),
        user_channel_id: 249229645327869497816677360056284350486,
        feerate_sat_per_1000_weight: Some(23500),
        balance_msat: 359454101,
        outbound_capacity_msat: 339454101,
        next_outbound_htlc_limit_msat: 289258101,
        next_outbound_htlc_minimum_msat: 21196000,
        inbound_capacity_msat: 1620545899,
        confirmations_required: Some(3),
        confirmations: Some(12882),
        force_close_spend_delay: Some(144),
        is_outbound: true,
        is_channel_ready: true,
        channel_shutdown_state: Some(NotShuttingDown),
        is_usable: true,
        is_public: false,
        inbound_htlc_minimum_msat: Some(1),
        inbound_htlc_maximum_msat: Some(1960000000),
        config: Some(ChannelConfig {
            forwarding_fee_proportional_millionths: 0,
            forwarding_fee_base_msat: 1000,
            cltv_expiry_delta: 72,
            max_dust_htlc_exposure: FixedLimitMsat(20000000),
            force_close_avoidance_max_fee_satoshis: 1000,
            accept_underpaying_htlcs: false
        })
    },
    ChannelDetails {
        channel_id: ChannelId([
            118, 29, 15, 136, 250, 241, 128, 51, 154, 44, 186, 253, 
            111, 40, 217, 201, 74, 213, 96, 219, 50, 31, 244, 102, 
            161, 79, 165, 25, 217, 168, 90, 235
        ]),
        counterparty: ChannelCounterparty {
            node_id: PublicKey(
                f0e18eca0f86800041211951fbbbabdbb7743995059d12a4219b00b4fb43faaec9a0af987303533c
                daa9a57b32494716c973a7a53696dd46367cb483a5fa46e6
            ),
            features: [162, 105, 10, 10, 0, 160, 8],
            unspendable_punishment_reserve: 10000,
            forwarding_info: Some(CounterpartyForwardingInfo {
                fee_base_msat: 1000,
                fee_proportional_millionths: 10,
                cltv_expiry_delta: 34
            }),
            outbound_htlc_minimum_msat: Some(0),
            outbound_htlc_maximum_msat: Some(980000000)
        },
        funding_txo: Some(OutPoint {
            txid: eb5aa8d919a54fa166f41f32db60d54ac9d9286ffdba2c9a3380f1fa880f1d76,
            index: 0
        }),
        channel_type: Some([0, 16]),
        short_channel_id: Some(895805108656537600),
        outbound_scid_alias: Some(837665132751028224),
        inbound_scid_alias: None,
        channel_value_satoshis: 1000000,
        unspendable_punishment_reserve: Some(10000),
        user_channel_id: 119403029337559860442125695504218248759,
        feerate_sat_per_1000_weight: Some(23500),
        balance_msat: 504471097,
        outbound_capacity_msat: 494471097,
        next_outbound_htlc_limit_msat: 444275097,
        next_outbound_htlc_minimum_msat: 21196000,
        inbound_capacity_msat: 485528903,
        confirmations_required: Some(3),
        confirmations: Some(1152),
        force_close_spend_delay: Some(144),
        is_outbound: true,
        is_channel_ready: true,
        channel_shutdown_state: Some(NotShuttingDown),
        is_usable: true,
        is_public: false,
        inbound_htlc_minimum_msat: Some(1),
        inbound_htlc_maximum_msat: Some(980000000),
        config: Some(ChannelConfig {
            forwarding_fee_proportional_millionths: 0,
            forwarding_fee_base_msat: 1000,
            cltv_expiry_delta: 72,
            max_dust_htlc_exposure: FixedLimitMsat(20000000),
            force_close_avoidance_max_fee_satoshis: 1000,
            accept_underpaying_htlcs: false
        })
    }
]
@tnull
Copy link
Contributor

tnull commented Nov 9, 2023

It seems that indeed most candidates were excluded due to not meeting the max_total_routing_fee_msat, followed by the htlc_minimum_msat limit.

I see two course of actions here:

  1. Revert Set a default max_total_routing_fee_msat of 1% + 50sats #2603 or at least significantly relax the default value.
  2. Indeed allow to override the max_total_routing_fee_msat value. However, do we possibly want to introduce a pay_invoice-like interface that more generally allows to override the default parameters of RouteParameters on a per-payment basis?

On LDK Node I so far also had put off overriding the default value as the interface doesn't really lend itself nicely to be overridden (e.g., the 1% + 50sats default value is impossible to replicate via a config option: either you allow the user to set a hard total limit or a percentage, but both doesn't work in a single value). See this related issue on LDK Node: lightningdevkit/ldk-node#166

To me, a combination of 1) and 2) would make the most sense.

@TonyGiorgio
Copy link
Contributor Author

We're going to go ahead and remove the fee here: MutinyWallet/mutiny-node#834

I don't know why it's happening all of a sudden and why no payment attempt is even tried. I had this issue on one existing wallet, then created a new one and it didn't have the issue. Then the next day the new wallet was running into it and we're getting user reports that no payments are going out. I'm seeing this up to 10k sats which I believe is ridiculous and I'm kind of surprised it's hitting fee limits. Perhaps there's a bug with the implementation of max fees.

@TonyGiorgio
Copy link
Contributor Author

TonyGiorgio commented Nov 9, 2023

Removing the fee limits did not work. I still cannot send payments under 20k sats.

Here is a series of payments I attempt from 21 sats to 50k sats.

mutiny-logs (9).txt

@TheBlueMatt
Copy link
Collaborator

Sorry for the delay, the issue you're hitting is this:

255e 2023-11-08 16:21:07.703 TRACE [lightning::routing::router:2433] Ignoring first hop with SCID 882907837178052609 due to its htlc_minimum_msat limit.
255e 2023-11-08 16:21:07.703 TRACE [lightning::routing::router:2433] Ignoring first hop with SCID 895805108656537600 due to its htlc_minimum_msat limit.

So LDK wasn't able to use either of its two outbound channels and promptly couldn't find a route. That htlc minimum is the next_outbound_htlc_minimum_msat in the ChannelDetails (both of which are ~21K sats). That can go high in one of two cases: either the counterparty set it high (in this case they did not), or we're limited by our max_dust_htlc_exposure (https://docs.rs/lightning/latest/lightning/util/config/struct.ChannelConfig.html#structfield.max_dust_htlc_exposure). If channel fees have gone up substantially, for non-anchor channels, the dust exposure may also slip up and the htlc-minimum gets set to the dust limit. You can try increasing the dust exposure (probably setting it to a FeeRateMultiplier, which allows it to scale with feerates).

@tnull
Copy link
Contributor

tnull commented Nov 9, 2023

Removing the fee limits did not work. I still cannot send payments under 20k sats.

Here is a series of payments I attempt from 21 sats to 50k sats.

mutiny-logs (9).txt

Yes, very likely the general issue is not the maximum fee limit, but the htlc_minimun_msat, see the logs:

Ignored 430 candidate hops due to insufficient value contribution, 0 due to path length limit, 169 due to CLTV delta limit, 0 due to previous payment failure, 13005 due to htlc_minimum_msat limit, 331 to avoid overpaying, 0 due to maximum total fee limit. Total: 13935 ignored candidates.

This is likely due to the recent fee spike rendering your small payments dust. There is sadly not much to do about that, besides adjusting the dust exposure limit, as Matt just mentioned.

@benthecarman
Copy link
Contributor

benthecarman commented Nov 9, 2023

We set out dust exposure limit to u64::MAX to try to get around this and it still happens

@benthecarman
Copy link
Contributor

benthecarman commented Nov 9, 2023

If I change it to u64::max / 2 it starts working on our signet at least, maybe there is an overflow happening somewhere.

Looks like it is being cast as a i64 which is undefined behavior

@tnull
Copy link
Contributor

tnull commented Nov 9, 2023

If I change it to u64::max / 2 it starts working on our signet at least, maybe there is an overflow happening somewhere

FWIW, I just replicated this behavior in LDK Node tests.

@benthecarman
Copy link
Contributor

benthecarman commented Nov 9, 2023

made #2722 which should fix those potential overflows / undefined behavior

@TonyGiorgio
Copy link
Contributor Author

Thanks for the help here. By implementing a large value here we've been able to send smaller amounts again. Feel free to close this unless you want to use it as a tracker for #2722

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants