lightning zero conf channel stuck in CHANNELD_AWAITING_LOCKIN sometimes: Owning subdaemon channeld died

zero conf channel stuck in CHANNELD_AWAITING_LOCKIN sometimes: Owning subdaemon channeld died

Open JssDWt opened this issue 1 year ago • 9 comments

Issue and Steps to Reproduce

There is a CLN v22.11 node that opens a zero conf channel to another CLN v22.11 node. When running my integration tests on regtest, regularly the opened channel is stuck in CHANNELD_AWAITING_LOCKIN. The most relevant log line is: 2022-12-10T20:46:28.159Z INFO 036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-chan#2: Peer transient failure in CHANNELD_AWAITING_LOCKIN: channeld: Owning subdaemon channeld died (0)

There appears to be no recovery from the dying channeld subdaemon at this point.

Here's the relevant logs:

Failing flow

Channel funder

2022-12-10T20:46:28.113Z DEBUG   plugin-spenderp: mfc 50: multiconnect.
2022-12-10T20:46:28.113Z DEBUG   plugin-spenderp: mfc 50, dest 0: connect 036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894.
2022-12-10T20:46:28.113Z DEBUG   lightningd: Already connected via 127.0.0.1:63328
2022-12-10T20:46:28.113Z DEBUG   plugin-spenderp: mfc 50, dest 0: connect done.
2022-12-10T20:46:28.113Z DEBUG   plugin-spenderp: mfc 50: multiconnect done.
2022-12-10T20:46:28.115Z DEBUG   plugin-spenderp: mfc 50: 'parsefeerate' done
2022-12-10T20:46:28.115Z DEBUG   plugin-spenderp: mfc 50: fundpsbt.
2022-12-10T20:46:28.116Z DEBUG   plugin-spenderp: mfc 50: fundpsbt done.
2022-12-10T20:46:28.117Z DEBUG   plugin-spenderp: mfc 50: fundchannel_start parallel with PSBT cHNidP8BADMCAAAAARPcNOkysvYut5ReANK9TgyXmxmXbBHH39pdFoMUbfrMAQAAAAD9////AG0AAAAAAQDeAgAAAAABAbMOpwAWjSzI6is3S0e7xgFb0MjI4TRnZqXv76yEfHaJAAAAAAD+////AubD1CgBAAAAFgAUXIDDCoWo/7s2zydpDQWRQk5exMWAlpgAAAAAABYAFKTaT/DpgOneP8xgQlOdynyGXwEoAkcwRAIgY5CQKsBTQJF0XH3cn/82ZMm+Kex6+UPgVp9+8chTFacCICQIcHZSINMuy/4hSGKVf/RRrf7Mtcv6hTlX/mqH3CY/ASECyLhFsZvHqwbNloUg10uM/2wyIG9ez5uABodBdxJW+H9mAAAAAQEfgJaYAAAAAAAWABSk2k/w6YDp3j/MYEJTncp8hl8BKAz8CWxpZ2h0bmluZwEIs3emJLA0mfgM/AlsaWdodG5pbmcCAgABAA==
2022-12-10T20:46:28.117Z DEBUG   plugin-spenderp: mfc 50, dest 0: fundchannel_start 036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894.
2022-12-10T20:46:28.117Z DEBUG   lightningd: fundchannel_start: allocating uncommitted_channel
2022-12-10T20:46:28.117Z INFO    lightningd: Will open private channel with node 036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894
2022-12-10T20:46:28.120Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: pid 30849, msgfd 70
2022-12-10T20:46:28.120Z DEBUG   hsmd: Client: Received message 30 from client
2022-12-10T20:46:28.120Z DEBUG   hsmd: Client: Received message 10 from client
2022-12-10T20:46:28.120Z DEBUG   hsmd: new_client: 2
2022-12-10T20:46:28.124Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:46:28.124Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: funder_channel_start
2022-12-10T20:46:28.124Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:46:28.125Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: Setting their reserve to 0sat
2022-12-10T20:46:28.125Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: peer_out WIRE_OPEN_CHANNEL
2022-12-10T20:46:28.125Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: billboard: Funding channel start: offered, now waiting for accept_channel
2022-12-10T20:46:28.134Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: peer_in WIRE_ACCEPT_CHANNEL
2022-12-10T20:46:28.134Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: accept_channel: max_htlc_value_in_flight=18446744073709551615msat, channel_reserve=1021sat, htlc_minimum=0msat, minimum_depth=1
2022-12-10T20:46:28.134Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: We negotiated option_zeroconf, using our minimum_depth=0
2022-12-10T20:46:28.134Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: billboard: Funding channel start: awaiting funding_txid with output to 0020d6036a171ff01fc7f094d9f6c4552a5c3002601c05d29180dad41981cd61f472
2022-12-10T20:46:28.135Z DEBUG   plugin-spenderp: mfc 50, dest 0: fundchannel_start 036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894 done.
2022-12-10T20:46:28.135Z DEBUG   plugin-spenderp: mfc 50: parallel channel starts done.
2022-12-10T20:46:28.135Z DEBUG   plugin-spenderp: mfc 50: Creating funding tx.
2022-12-10T20:46:28.135Z DEBUG   plugin-spenderp: mfc 50: funding tx 573811fc7a69ab21b0475f56687b492fabdc9e10de3f63e4c9d4f6467af8ede4: 036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894: 102100sat, change: 9897746sat
2022-12-10T20:46:28.135Z DEBUG   plugin-spenderp: mfc 50: parallel fundchannel_complete.
2022-12-10T20:46:28.135Z DEBUG   plugin-spenderp: mfc 50, dest 0: fundchannel_complete 036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894.
2022-12-10T20:46:28.135Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: billboard: Funding channel con't: continuing with funding_txid 573811fc7a69ab21b0475f56687b492fabdc9e10de3f63e4c9d4f6467af8ede4
2022-12-10T20:46:28.135Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-hsmd: Got WIRE_HSMD_READY_CHANNEL
2022-12-10T20:46:28.135Z DEBUG   hsmd: Client: Received message 31 from client
2022-12-10T20:46:28.138Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-hsmd: Got WIRE_HSMD_SIGN_REMOTE_COMMITMENT_TX
2022-12-10T20:46:28.138Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: signature 3044022077fa0b4dad77d2c96d1fda4641b44e241bc3298894a8ea09520749769482bdd102205629ed37b65642833f252bf9dfa5d6148589d5c783be0bc29a8ac6c090bdafb401 on tx 0200000001e4edf87a46f6d4c9e4633fde109edcab2f497b68565f47b021ab697afc11385700000000003c740580011d8e010000000000160014dad6e943e05148c1e8b157e57f237ccee4dcc76ac3de3c20 using key 02abeb3d4492e44f800aceed0e3f507333ea5f20b0a9c986b0c49f6a02e889862e
2022-12-10T20:46:28.139Z DEBUG   hsmd: Client: Received message 19 from client
2022-12-10T20:46:28.139Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: peer_out WIRE_FUNDING_CREATED
2022-12-10T20:46:28.139Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: billboard: Funding channel: create first tx, now waiting for their signature
2022-12-10T20:46:28.149Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: peer_in WIRE_FUNDING_SIGNED
2022-12-10T20:46:28.150Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-hsmd: Got WIRE_HSMD_VALIDATE_COMMITMENT_TX
2022-12-10T20:46:28.150Z DEBUG   hsmd: Client: Received message 35 from client
2022-12-10T20:46:28.150Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: billboard: Funding channel: opening negotiation succeeded
2022-12-10T20:46:28.151Z DEBUG   lightningd: 0379e9853582eca69ea52e3368a788edbe5ae55cc0793c8b47546e5877247911b6
2022-12-10T20:46:28.154Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-channeld-chan#2: pid 30852, msgfd 72
2022-12-10T20:46:28.154Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-chan#2: Waiting for funding confirmations
2022-12-10T20:46:28.154Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-chan#2: Ignoring fee limits!
2022-12-10T20:46:28.154Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-chan#2: attempting update blockheight e4edf87a46f6d4c9e4633fde109edcab2f497b68565f47b021ab697afc113857
2022-12-10T20:46:28.154Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-openingd-chan#2: Status closed, but not exited. Killing
2022-12-10T20:46:28.156Z DEBUG   hsmd: new_client: 2
2022-12-10T20:46:28.157Z DEBUG   plugin-spenderp: mfc 50, dest 0: fundchannel_complete 036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894 done.
2022-12-10T20:46:28.157Z DEBUG   plugin-spenderp: mfc 50: parallel fundchannel_complete  done.
2022-12-10T20:46:28.157Z DEBUG   plugin-spenderp: mfc 50: signpsbt.
2022-12-10T20:46:28.157Z DEBUG   hsmd: Client: Received message 7 from client
2022-12-10T20:46:28.157Z DEBUG   lightningd: sendrawtransaction: 0200000000010113dc34e932b2f62eb7945e00d2bd4e0c979b19976c11c7dfda5d1683146dfacc0100000000fdffffff02d48e010000000000220020d6036a171ff01fc7f094d9f6c4552a5c3002601c05d29180dad41981cd61f4721207970000000000160014add75f3fa7f82f0d2c52d88c5ea8ed5c23fc267d024730440220499e4745b44e5dedc9dd13eb08f807b5dd6497ffefbfec9db4c03640a63211e20220019aaf72c77a071b600f4aa1df5819ae68bf8fcd27a1a818b9d03399ef21c7f5012103fa8b3f76f38950651f026ccd40d0024d2912c96579098780d9ac7928b29308a26d000000
2022-12-10T20:46:28.159Z DEBUG   plugin-spenderp: mfc 50: signpsbt done.
2022-12-10T20:46:28.159Z DEBUG   plugin-spenderp: mfc 50: sendpsbt.
2022-12-10T20:46:28.159Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-channeld-chan#2: option_static_remotekey = 1, option_anchor_outputs = 0
2022-12-10T20:46:28.159Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-channeld-chan#2: init LOCAL: remote_per_commit = 0379e9853582eca69ea52e3368a788edbe5ae55cc0793c8b47546e5877247911b6, old_remote_per_commit = 0379e9853582eca69ea52e3368a788edbe5ae55cc0793c8b47546e5877247911b6 next_idx_local = 1 next_idx_remote = 1 revocations_received = 0 feerates { SENT_ADD_ACK_REVOCATION:253 } range 253-4294967295 blockheights { SENT_ADD_ACK_REVOCATION:0 }, our current 109
2022-12-10T20:46:28.159Z INFO    036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-chan#2: Peer transient failure in CHANNELD_AWAITING_LOCKIN: channeld: Owning subdaemon channeld died (0)
2022-12-10T20:46:28.159Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:46:28.159Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:46:28.165Z DEBUG   plugin-bcli: sendrawtx exit 0 (bitcoin-cli -regtest -datadir=miner2503483624 -rpcport=61949 -rpcuser=... -stdinrpcpass sendrawtransaction 0200000000010113dc34e932b2f62eb7945e00d2bd4e0c979b19976c11c7dfda5d1683146dfacc0100000000fdffffff02d48e010000000000220020d6036a171ff01fc7f094d9f6c4552a5c3002601c05d29180dad41981cd61f4721207970000000000160014add75f3fa7f82f0d2c52d88c5ea8ed5c23fc267d024730440220499e4745b44e5dedc9dd13eb08f807b5dd6497ffefbfec9db4c03640a63211e20220019aaf72c77a071b600f4aa1df5819ae68bf8fcd27a1a818b9d03399ef21c7f5012103fa8b3f76f38950651f026ccd40d0024d2912c96579098780d9ac7928b29308a26d000000) 
2022-12-10T20:46:28.166Z DEBUG   wallet: Owning output 1 9897746sat (SEGWIT) txid 573811fc7a69ab21b0475f56687b492fabdc9e10de3f63e4c9d4f6467af8ede4
2022-12-10T20:46:28.167Z DEBUG   plugin-spenderp: mfc 50: sendpsbt done.
2022-12-10T20:46:28.167Z DEBUG   plugin-spenderp: mfc 50: done.
2022-12-10T20:46:28.167Z DEBUG   plugin-spenderp: mfc 50: cleanup!
2022-12-10T20:46:28.167Z DEBUG   plugin-spenderp: mfc 50: cleanup done, finishing command.

Accepting peer

2022-12-10T20:46:28.036Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-connectd: Connected out, starting crypto
2022-12-10T20:46:28.037Z DEBUG   036cf43e0ede57d72dfeabd0795fdc5f76244b396c9f19333e2ed1d89fcce90894-hsmd: Got WIRE_HSMD_ECDH_REQ
2022-12-10T20:46:28.037Z DEBUG   hsmd: Client: Received message 1 from client
2022-12-10T20:46:28.037Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-connectd: Connect OUT
2022-12-10T20:46:28.037Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-connectd: peer_out WIRE_INIT
2022-12-10T20:46:28.037Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-connectd: peer_in WIRE_INIT
2022-12-10T20:46:28.037Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: seeker: chosen as startup peer
2022-12-10T20:46:28.038Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-connectd: Handed peer, entering loop
2022-12-10T20:46:28.038Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: seeker: starting gossip
2022-12-10T20:46:28.038Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-connectd: peer_out WIRE_GOSSIP_TIMESTAMP_FILTER
2022-12-10T20:46:28.038Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: Received channel_announcement for channel 104x1x0
2022-12-10T20:46:28.038Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: Updated pending announce with update 104x1x0/0
2022-12-10T20:46:28.038Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: Updated pending announce with update 104x1x0/1
2022-12-10T20:46:28.038Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: Updated pending announce with update 104x1x0/0
2022-12-10T20:46:28.038Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: Updated pending announce with update 104x1x0/1
2022-12-10T20:46:28.039Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: Received node_announcement for node 02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6
2022-12-10T20:46:28.039Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: Received channel_update for channel 104x1x0/0 now ACTIVE
2022-12-10T20:46:28.039Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: Received channel_update for channel 104x1x0/1 now ACTIVE
2022-12-10T20:46:28.125Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-connectd: Activating for message WIRE_OPEN_CHANNEL
2022-12-10T20:46:28.128Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-openingd-chan#1: pid 30850, msgfd 69
2022-12-10T20:46:28.128Z DEBUG   hsmd: Client: Received message 30 from client
2022-12-10T20:46:28.128Z DEBUG   hsmd: Client: Received message 10 from client
2022-12-10T20:46:28.128Z DEBUG   hsmd: new_client: 1
2022-12-10T20:46:28.133Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:46:28.133Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:46:28.133Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-openingd-chan#1: peer_in WIRE_OPEN_CHANNEL
2022-12-10T20:46:28.133Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-openingd-chan#1: Setting their reserve to 1021sat
2022-12-10T20:46:28.133Z DEBUG   lightningd: Calling openchannel hook of plugin start_zero_conf_plugin.sh
2022-12-10T20:46:28.133Z INFO    plugin-start_zero_conf_plugin.sh: {'id': '02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6', 'funding_msat': 102100000, 'push_msat': 0, 'dust_limit_msat': 546000, 'max_htlc_value_in_flight_msat': 18446744073709551615, 'channel_reserve_msat': 0, 'htlc_minimum_msat': 0, 'feerate_per_kw': 253, 'to_self_delay': 6, 'max_accepted_htlcs': 30, 'channel_flags': 0}
2022-12-10T20:46:28.133Z INFO    plugin-start_zero_conf_plugin.sh: This peer is in the zeroconf allowlist, setting mindepth=0
2022-12-10T20:46:28.133Z DEBUG   lightningd: Plugin start_zero_conf_plugin.sh returned from openchannel hook call
2022-12-10T20:46:28.133Z DEBUG   lightningd: Setting mindepth=0 for this channel as requested by the openchannel hook
2022-12-10T20:46:28.134Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-openingd-chan#1: peer_out WIRE_ACCEPT_CHANNEL
2022-12-10T20:46:28.134Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-openingd-chan#1: billboard: Incoming channel: accepted, now waiting for them to create funding tx
2022-12-10T20:46:28.139Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-openingd-chan#1: peer_in WIRE_FUNDING_CREATED
2022-12-10T20:46:28.139Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-hsmd: Got WIRE_HSMD_READY_CHANNEL
2022-12-10T20:46:28.139Z DEBUG   hsmd: Client: Received message 31 from client
2022-12-10T20:46:28.140Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-hsmd: Got WIRE_HSMD_VALIDATE_COMMITMENT_TX
2022-12-10T20:46:28.140Z DEBUG   hsmd: Client: Received message 35 from client
2022-12-10T20:46:28.141Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-hsmd: Got WIRE_HSMD_SIGN_REMOTE_COMMITMENT_TX
2022-12-10T20:46:28.141Z DEBUG   hsmd: Client: Received message 19 from client
2022-12-10T20:46:28.141Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-chan#1: Got opening_fundee_finish_response
2022-12-10T20:46:28.142Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-chan#1: Watching funding tx 573811fc7a69ab21b0475f56687b492fabdc9e10de3f63e4c9d4f6467af8ede4
2022-12-10T20:46:28.145Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-channeld-chan#1: pid 30851, msgfd 70
2022-12-10T20:46:28.145Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-chan#1: Waiting for funding confirmations
2022-12-10T20:46:28.145Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-chan#1: Ignoring fee limits!
2022-12-10T20:46:28.145Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-openingd-chan#1: Status closed, but not exited. Killing
2022-12-10T20:46:28.146Z DEBUG   hsmd: new_client: 1
2022-12-10T20:46:28.149Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-channeld-chan#1: option_static_remotekey = 1, option_anchor_outputs = 0
2022-12-10T20:46:28.149Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-channeld-chan#1: init REMOTE: remote_per_commit = 02e51997030304788e534c0cb4ccfe04408d295df3e0e23a2b98c57c341d67b62c, old_remote_per_commit = 02e51997030304788e534c0cb4ccfe04408d295df3e0e23a2b98c57c341d67b62c next_idx_local = 1 next_idx_remote = 1 revocations_received = 0 feerates { RCVD_ADD_ACK_REVOCATION:253 } range 253-4294967295 blockheights { RCVD_ADD_ACK_REVOCATION:0 }, our current 109
2022-12-10T20:46:28.149Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:46:28.149Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:46:28.149Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-channeld-chan#1: peer_out WIRE_FUNDING_SIGNED
2022-12-10T20:46:28.149Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-channeld-chan#1: billboard: Funding needs 0 more confirmations to be ready.
2022-12-10T20:46:28.149Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-channeld-chan#1: channel_ready: sending commit index 1: 031afd03afb19b487e9d0bc5aed1c2687a4c3dd40b6ee3a909d47e1e372a0b3960
2022-12-10T20:46:28.149Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:46:28.149Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:46:28.149Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-channeld-chan#1: peer_out WIRE_CHANNEL_READY
2022-12-10T20:46:28.149Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-channeld-chan#1: billboard: We've confirmed channel ready, they haven't yet.
2022-12-10T20:46:28.563Z DEBUG   lightningd: ... feerate estimate for opening hit floor 253
2022-12-10T20:46:28.563Z DEBUG   lightningd: ... feerate estimate for mutual_close hit floor 253
2022-12-10T20:46:28.563Z DEBUG   lightningd: ... feerate estimate for unilateral_close hit floor 253
2022-12-10T20:46:28.563Z DEBUG   lightningd: ... feerate estimate for delayed_to_us hit floor 253
2022-12-10T20:46:28.563Z DEBUG   lightningd: ... feerate estimate for htlc_resolution hit floor 253
2022-12-10T20:46:28.564Z DEBUG   lightningd: ... feerate estimate for penalty hit floor 253
2022-12-10T20:46:28.564Z DEBUG   lightningd: ... polled feerate estimate for min_acceptable (125) smoothed to 250 (alpha=0.02)
2022-12-10T20:46:28.564Z DEBUG   lightningd: ... feerate estimate for min_acceptable hit floor 253
2022-12-10T20:46:29.039Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: Received node_announcement for node 02d0928b9effc19197ae42b0aa027e6f9b8cb7691dbb7e4076b80e90830049db62
2022-12-10T20:46:29.594Z DEBUG   lightningd: ... feerate estimate for opening hit floor 253
2022-12-10T20:46:29.594Z DEBUG   lightningd: ... feerate estimate for mutual_close hit floor 253
2022-12-10T20:46:29.594Z DEBUG   lightningd: ... feerate estimate for unilateral_close hit floor 253
2022-12-10T20:46:29.594Z DEBUG   lightningd: ... feerate estimate for delayed_to_us hit floor 253
2022-12-10T20:46:29.595Z DEBUG   lightningd: ... feerate estimate for htlc_resolution hit floor 253
2022-12-10T20:46:29.595Z DEBUG   lightningd: ... feerate estimate for penalty hit floor 253
2022-12-10T20:46:29.595Z DEBUG   lightningd: ... polled feerate estimate for min_acceptable (125) smoothed to 250 (alpha=0.02)
2022-12-10T20:46:29.595Z DEBUG   lightningd: ... feerate estimate for min_acceptable hit floor 253
2022-12-10T20:46:30.624Z DEBUG   lightningd: ... feerate estimate for opening hit floor 253
2022-12-10T20:46:30.624Z DEBUG   lightningd: ... feerate estimate for mutual_close hit floor 253
2022-12-10T20:46:30.624Z DEBUG   lightningd: ... feerate estimate for unilateral_close hit floor 253
2022-12-10T20:46:30.624Z DEBUG   lightningd: ... feerate estimate for delayed_to_us hit floor 253
2022-12-10T20:46:30.624Z DEBUG   lightningd: ... feerate estimate for htlc_resolution hit floor 253
2022-12-10T20:46:30.624Z DEBUG   lightningd: ... feerate estimate for penalty hit floor 253
2022-12-10T20:46:30.624Z DEBUG   lightningd: ... polled feerate estimate for min_acceptable (125) smoothed to 250 (alpha=0.02)
2022-12-10T20:46:30.624Z DEBUG   lightningd: ... feerate estimate for min_acceptable hit floor 253
2022-12-10T20:46:31.653Z DEBUG   lightningd: ... feerate estimate for opening hit floor 253
2022-12-10T20:46:31.653Z DEBUG   lightningd: ... feerate estimate for mutual_close hit floor 253
2022-12-10T20:46:31.653Z DEBUG   lightningd: ... feerate estimate for unilateral_close hit floor 253
2022-12-10T20:46:31.653Z DEBUG   lightningd: ... feerate estimate for delayed_to_us hit floor 253
2022-12-10T20:46:31.653Z DEBUG   lightningd: ... feerate estimate for htlc_resolution hit floor 253
2022-12-10T20:46:31.653Z DEBUG   lightningd: ... feerate estimate for penalty hit floor 253
2022-12-10T20:46:31.653Z DEBUG   lightningd: ... polled feerate estimate for min_acceptable (125) smoothed to 250 (alpha=0.02)
2022-12-10T20:46:31.653Z DEBUG   lightningd: ... feerate estimate for min_acceptable hit floor 253
2022-12-10T20:46:32.676Z DEBUG   lightningd: ... feerate estimate for opening hit floor 253
2022-12-10T20:46:32.676Z DEBUG   lightningd: ... feerate estimate for mutual_close hit floor 253
2022-12-10T20:46:32.676Z DEBUG   lightningd: ... feerate estimate for unilateral_close hit floor 253
2022-12-10T20:46:32.676Z DEBUG   lightningd: ... feerate estimate for delayed_to_us hit floor 253
2022-12-10T20:46:32.676Z DEBUG   lightningd: ... feerate estimate for htlc_resolution hit floor 253
2022-12-10T20:46:32.676Z DEBUG   lightningd: ... feerate estimate for penalty hit floor 253
2022-12-10T20:46:32.676Z DEBUG   lightningd: ... polled feerate estimate for min_acceptable (125) smoothed to 250 (alpha=0.02)
2022-12-10T20:46:32.676Z DEBUG   lightningd: ... feerate estimate for min_acceptable hit floor 253
2022-12-10T20:46:33.414Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: seeker: startup peer finished
2022-12-10T20:46:33.414Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: seeker: state = PROBING_SCIDS Seeking scids 1 - 109
2022-12-10T20:46:33.414Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: sending query_channel_range for blocks 1+109
2022-12-10T20:46:33.417Z DEBUG   02c3212fb660988b1aac3b5cd3d4223cc254e61af0e9818ee0d192a574c3616ec6-gossipd: reply_channel_range 1+109 (of 1+109) 1 scids

Succesful flow

Channel funder

2022-12-10T20:47:50.054Z DEBUG   plugin-spenderp: mfc 50: multiconnect.
2022-12-10T20:47:50.054Z DEBUG   lightningd: Already connected via 127.0.0.1:49382
2022-12-10T20:47:50.054Z DEBUG   plugin-spenderp: mfc 50, dest 0: connect 031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1.
2022-12-10T20:47:50.054Z DEBUG   plugin-spenderp: mfc 50, dest 0: connect done.
2022-12-10T20:47:50.054Z DEBUG   plugin-spenderp: mfc 50: multiconnect done.
2022-12-10T20:47:50.056Z DEBUG   plugin-spenderp: mfc 50: 'parsefeerate' done
2022-12-10T20:47:50.056Z DEBUG   plugin-spenderp: mfc 50: fundpsbt.
2022-12-10T20:47:50.056Z DEBUG   plugin-spenderp: mfc 50: fundpsbt done.
2022-12-10T20:47:50.058Z DEBUG   plugin-spenderp: mfc 50: fundchannel_start parallel with PSBT cHNidP8BADMCAAAAAW4PQSxCmP6RPhOf0f3fH4NjiAJJS729v07TVUlFXdnkAAAAAAD9////AGsAAAAAAQDeAgAAAAABAd1pi/9wcweiiOexIPqIdMGv3iweCPK3+pZ0wHKWrBkXAQAAAAD+////AoCWmAAAAAAAFgAURrTIj7cogzYIoCBUtl6b1szsKXPmw9QoAQAAABYAFJooDqzauCxFClWsUYWqnMtu0sAkAkcwRAIgUVNuIrwncLREX2hQAxB3ZSk17NRuvD4tB3uVY65Gv1gCICU1KJN9iVbBvVMsjDoYsCSjxJ88y5FNr/9EPhzeklTPASECo9hB5N0iOpLcnCntzcFLEt8o/8IDcOGpMtS8ENoxDiNmAAAAAQEfgJaYAAAAAAAWABRGtMiPtyiDNgigIFS2XpvWzOwpcwz8CWxpZ2h0bmluZwEIJu+CEQ4VUBgM/AlsaWdodG5pbmcCAgABAA==
2022-12-10T20:47:50.058Z DEBUG   lightningd: fundchannel_start: allocating uncommitted_channel
2022-12-10T20:47:50.058Z INFO    lightningd: Will open private channel with node 031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1
2022-12-10T20:47:50.062Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: pid 32339, msgfd 70
2022-12-10T20:47:50.062Z DEBUG   plugin-spenderp: mfc 50, dest 0: fundchannel_start 031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1.
2022-12-10T20:47:50.062Z DEBUG   hsmd: Client: Received message 30 from client
2022-12-10T20:47:50.062Z DEBUG   hsmd: Client: Received message 10 from client
2022-12-10T20:47:50.063Z DEBUG   hsmd: new_client: 2
2022-12-10T20:47:50.069Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:47:50.069Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: funder_channel_start
2022-12-10T20:47:50.069Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:47:50.069Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: Setting their reserve to 0sat
2022-12-10T20:47:50.069Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: peer_out WIRE_OPEN_CHANNEL
2022-12-10T20:47:50.069Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: billboard: Funding channel start: offered, now waiting for accept_channel
2022-12-10T20:47:50.081Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: peer_in WIRE_ACCEPT_CHANNEL
2022-12-10T20:47:50.082Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: accept_channel: max_htlc_value_in_flight=18446744073709551615msat, channel_reserve=1021sat, htlc_minimum=0msat, minimum_depth=1
2022-12-10T20:47:50.082Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: We negotiated option_zeroconf, using our minimum_depth=0
2022-12-10T20:47:50.082Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: billboard: Funding channel start: awaiting funding_txid with output to 002071c0505062dca4cf58ac4d11c3a661473445812a2f592b8c59dc0d27b728ffde
2022-12-10T20:47:50.082Z DEBUG   plugin-spenderp: mfc 50, dest 0: fundchannel_start 031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1 done.
2022-12-10T20:47:50.082Z DEBUG   plugin-spenderp: mfc 50: parallel channel starts done.
2022-12-10T20:47:50.082Z DEBUG   plugin-spenderp: mfc 50: Creating funding tx.
2022-12-10T20:47:50.082Z DEBUG   plugin-spenderp: mfc 50: funding tx 8ec4ee4dd01e079a1e79e74dbd578d9b5ac89705141dbac2f9733bb6d93f1fe5: change: 9897746sat, 031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1: 102100sat
2022-12-10T20:47:50.082Z DEBUG   plugin-spenderp: mfc 50: parallel fundchannel_complete.
2022-12-10T20:47:50.082Z DEBUG   plugin-spenderp: mfc 50, dest 0: fundchannel_complete 031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1.
2022-12-10T20:47:50.083Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: billboard: Funding channel con't: continuing with funding_txid 8ec4ee4dd01e079a1e79e74dbd578d9b5ac89705141dbac2f9733bb6d93f1fe5
2022-12-10T20:47:50.083Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-hsmd: Got WIRE_HSMD_READY_CHANNEL
2022-12-10T20:47:50.083Z DEBUG   hsmd: Client: Received message 31 from client
2022-12-10T20:47:50.085Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-hsmd: Got WIRE_HSMD_SIGN_REMOTE_COMMITMENT_TX
2022-12-10T20:47:50.086Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: signature 3044022007c4e7044d537aa3c7f05f7f97194181c2ba2a3efc84b8ffe007f2c8cb0f179f022006c0219871d1321378e07258fc0790d95d712ae40344c02bd0fa99739b035e5901 on tx 0200000001e51f3fd9b63b73f9c2ba1d140597c85a9b8d57bd4de7791e9a071ed04deec48e01000000003d6ebb80011d8e0100000000001600146ad6a73a69c1febacc793f77d19d6e0aee1b8b8a9a9e1420 using key 03141b9199751b1ba31bc2fd37b872f7fad7d7f5936e94ca2dfb67fbaf76b46399
2022-12-10T20:47:50.086Z DEBUG   hsmd: Client: Received message 19 from client
2022-12-10T20:47:50.086Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: peer_out WIRE_FUNDING_CREATED
2022-12-10T20:47:50.086Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: billboard: Funding channel: create first tx, now waiting for their signature
2022-12-10T20:47:50.099Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: peer_in WIRE_FUNDING_SIGNED
2022-12-10T20:47:50.099Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-hsmd: Got WIRE_HSMD_VALIDATE_COMMITMENT_TX
2022-12-10T20:47:50.099Z DEBUG   hsmd: Client: Received message 35 from client
2022-12-10T20:47:50.100Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: billboard: Funding channel: opening negotiation succeeded
2022-12-10T20:47:50.100Z DEBUG   lightningd: 02c028c3be3eba1509e6f5e67e490a898e59541e430aa91bdfd2bdbd204454e63d
2022-12-10T20:47:50.104Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-channeld-chan#2: pid 32346, msgfd 72
2022-12-10T20:47:50.104Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-chan#2: Waiting for funding confirmations
2022-12-10T20:47:50.104Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-chan#2: Ignoring fee limits!
2022-12-10T20:47:50.104Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-chan#2: attempting update blockheight e51f3fd9b63b73f9c2ba1d140597c85a9b8d57bd4de7791e9a071ed04deec48f
2022-12-10T20:47:50.104Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-openingd-chan#2: Status closed, but not exited. Killing
2022-12-10T20:47:50.105Z DEBUG   hsmd: new_client: 2
2022-12-10T20:47:50.107Z DEBUG   plugin-spenderp: mfc 50, dest 0: fundchannel_complete 031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1 done.
2022-12-10T20:47:50.107Z DEBUG   plugin-spenderp: mfc 50: parallel fundchannel_complete  done.
2022-12-10T20:47:50.107Z DEBUG   plugin-spenderp: mfc 50: signpsbt.
2022-12-10T20:47:50.107Z DEBUG   hsmd: Client: Received message 7 from client
2022-12-10T20:47:50.107Z DEBUG   lightningd: sendrawtransaction: 020000000001016e0f412c4298fe913e139fd1fddf1f83638802494bbdbdbf4ed35549455dd9e40000000000fdffffff021207970000000000160014226e0a0d45a01e73493fed542d2975a0ba6f37abd48e01000000000022002071c0505062dca4cf58ac4d11c3a661473445812a2f592b8c59dc0d27b728ffde024730440220789cba9f4d60c3abb32653ba1f08731838d9ea81d94d11f6c79fe8e4e34298b302206809fd4f0713baa322407be06be3e2a393cc109ba9bb85f4d141ef03f5b294320121023b197858ca96b84051d4770b0e26af9dbd303ca12571e68dc01bcbfdbc47d42c6b000000
2022-12-10T20:47:50.109Z DEBUG   plugin-spenderp: mfc 50: signpsbt done.
2022-12-10T20:47:50.109Z DEBUG   plugin-spenderp: mfc 50: sendpsbt.
2022-12-10T20:47:50.109Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-channeld-chan#2: option_static_remotekey = 1, option_anchor_outputs = 0
2022-12-10T20:47:50.109Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-channeld-chan#2: init LOCAL: remote_per_commit = 02c028c3be3eba1509e6f5e67e490a898e59541e430aa91bdfd2bdbd204454e63d, old_remote_per_commit = 02c028c3be3eba1509e6f5e67e490a898e59541e430aa91bdfd2bdbd204454e63d next_idx_local = 1 next_idx_remote = 1 revocations_received = 0 feerates { SENT_ADD_ACK_REVOCATION:253 } range 253-4294967295 blockheights { SENT_ADD_ACK_REVOCATION:0 }, our current 115
2022-12-10T20:47:50.109Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:47:50.109Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:47:50.109Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-channeld-chan#2: billboard: Funding needs 0 more confirmations to be ready.
2022-12-10T20:47:50.110Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-channeld-chan#2: channel_ready: sending commit index 1: 03cb761529f8b62d0f0f38035fcdeea74fc79ac61da08c5850ff25e2a1a97a3926
2022-12-10T20:47:50.110Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:47:50.110Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:47:50.110Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-channeld-chan#2: peer_out WIRE_CHANNEL_READY
2022-12-10T20:47:50.110Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-channeld-chan#2: billboard: We've confirmed channel ready, they haven't yet.
2022-12-10T20:47:50.110Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-channeld-chan#2: peer_in WIRE_CHANNEL_READY
2022-12-10T20:47:50.110Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-channeld-chan#2: Peer told us that they'll use alias=2739350x10579728x65251 for this channel
2022-12-10T20:47:50.110Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-chan#2: Got channel_ready
2022-12-10T20:47:50.111Z INFO    031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-chan#2: State changed from CHANNELD_AWAITING_LOCKIN to CHANNELD_NORMAL
2022-12-10T20:47:50.111Z DEBUG   lightningd: update_feerates: feerate = 253, min=253, max=4294967295, penalty=253
2022-12-10T20:47:50.111Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-chan#2: attempting update blockheight e51f3fd9b63b73f9c2ba1d140597c85a9b8d57bd4de7791e9a071ed04deec48f
2022-12-10T20:47:50.113Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-channeld-chan#2: billboard: Channel ready for use.
2022-12-10T20:47:50.113Z DEBUG   plugin-funder: Cleaning up datastore for channel_id e51f3fd9b63b73f9c2ba1d140597c85a9b8d57bd4de7791e9a071ed04deec48f
2022-12-10T20:47:50.114Z INFO    plugin-chanbackup: Updating the SCB
2022-12-10T20:47:50.114Z DEBUG   plugin-chanbackup: Updating the SCB file...
2022-12-10T20:47:50.114Z DEBUG   plugin-bookkeeper: coin_move 2 (channel_proposed) 102100000msat -0msat chain_mvt 1670705270
2022-12-10T20:47:50.116Z DEBUG   plugin-bcli: sendrawtx exit 0 (bitcoin-cli -regtest -datadir=miner2454834833 -rpcport=64271 -rpcuser=... -stdinrpcpass sendrawtransaction 020000000001016e0f412c4298fe913e139fd1fddf1f83638802494bbdbdbf4ed35549455dd9e40000000000fdffffff021207970000000000160014226e0a0d45a01e73493fed542d2975a0ba6f37abd48e01000000000022002071c0505062dca4cf58ac4d11c3a661473445812a2f592b8c59dc0d27b728ffde024730440220789cba9f4d60c3abb32653ba1f08731838d9ea81d94d11f6c79fe8e4e34298b302206809fd4f0713baa322407be06be3e2a393cc109ba9bb85f4d141ef03f5b294320121023b197858ca96b84051d4770b0e26af9dbd303ca12571e68dc01bcbfdbc47d42c6b000000) 
2022-12-10T20:47:50.117Z DEBUG   wallet: Owning output 0 9897746sat (SEGWIT) txid 8ec4ee4dd01e079a1e79e74dbd578d9b5ac89705141dbac2f9733bb6d93f1fe5
2022-12-10T20:47:50.119Z DEBUG   plugin-spenderp: mfc 50: sendpsbt done.
2022-12-10T20:47:50.119Z DEBUG   plugin-spenderp: mfc 50: done.
2022-12-10T20:47:50.119Z DEBUG   plugin-spenderp: mfc 50: cleanup!
2022-12-10T20:47:50.119Z DEBUG   plugin-spenderp: mfc 50: cleanup done, finishing command.

Accepting peer

2022-12-10T20:47:49.967Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-connectd: Connected out, starting crypto
2022-12-10T20:47:49.968Z DEBUG   031ce6de13373c3768e0e94f216ed212f52b19d2fc41f16568b38f09d9361ea0c1-hsmd: Got WIRE_HSMD_ECDH_REQ
2022-12-10T20:47:49.968Z DEBUG   hsmd: Client: Received message 1 from client
2022-12-10T20:47:49.968Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-connectd: Connect OUT
2022-12-10T20:47:49.968Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-connectd: peer_out WIRE_INIT
2022-12-10T20:47:49.969Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-connectd: peer_in WIRE_INIT
2022-12-10T20:47:49.969Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-connectd: Handed peer, entering loop
2022-12-10T20:47:49.969Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-gossipd: seeker: chosen as startup peer
2022-12-10T20:47:49.970Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-gossipd: seeker: starting gossip
2022-12-10T20:47:49.970Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-gossipd: Received channel_announcement for channel 104x1x0
2022-12-10T20:47:49.970Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-connectd: peer_out WIRE_GOSSIP_TIMESTAMP_FILTER
2022-12-10T20:47:49.970Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-gossipd: Updated pending announce with update 104x1x0/0
2022-12-10T20:47:49.970Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-gossipd: Updated pending announce with update 104x1x0/1
2022-12-10T20:47:49.971Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-gossipd: Received node_announcement for node 02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102
2022-12-10T20:47:49.971Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-gossipd: Received channel_update for channel 104x1x0/0 now ACTIVE
2022-12-10T20:47:49.971Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-gossipd: Received channel_update for channel 104x1x0/1 now ACTIVE
2022-12-10T20:47:50.069Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-connectd: Activating for message WIRE_OPEN_CHANNEL
2022-12-10T20:47:50.073Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-openingd-chan#1: pid 32341, msgfd 69
2022-12-10T20:47:50.074Z DEBUG   hsmd: Client: Received message 30 from client
2022-12-10T20:47:50.074Z DEBUG   hsmd: Client: Received message 10 from client
2022-12-10T20:47:50.074Z DEBUG   hsmd: new_client: 1
2022-12-10T20:47:50.079Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:47:50.079Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-openingd-chan#1: peer_in WIRE_OPEN_CHANNEL
2022-12-10T20:47:50.079Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:47:50.079Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-openingd-chan#1: Setting their reserve to 1021sat
2022-12-10T20:47:50.079Z DEBUG   lightningd: Calling openchannel hook of plugin start_zero_conf_plugin.sh
2022-12-10T20:47:50.080Z INFO    plugin-start_zero_conf_plugin.sh: {'id': '02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102', 'funding_msat': 102100000, 'push_msat': 0, 'dust_limit_msat': 546000, 'max_htlc_value_in_flight_msat': 18446744073709551615, 'channel_reserve_msat': 0, 'htlc_minimum_msat': 0, 'feerate_per_kw': 253, 'to_self_delay': 6, 'max_accepted_htlcs': 30, 'channel_flags': 0}
2022-12-10T20:47:50.081Z INFO    plugin-start_zero_conf_plugin.sh: This peer is in the zeroconf allowlist, setting mindepth=0
2022-12-10T20:47:50.081Z DEBUG   lightningd: Plugin start_zero_conf_plugin.sh returned from openchannel hook call
2022-12-10T20:47:50.081Z DEBUG   lightningd: Setting mindepth=0 for this channel as requested by the openchannel hook
2022-12-10T20:47:50.081Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-openingd-chan#1: peer_out WIRE_ACCEPT_CHANNEL
2022-12-10T20:47:50.081Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-openingd-chan#1: billboard: Incoming channel: accepted, now waiting for them to create funding tx
2022-12-10T20:47:50.086Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-openingd-chan#1: peer_in WIRE_FUNDING_CREATED
2022-12-10T20:47:50.086Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-hsmd: Got WIRE_HSMD_READY_CHANNEL
2022-12-10T20:47:50.086Z DEBUG   hsmd: Client: Received message 31 from client
2022-12-10T20:47:50.087Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-hsmd: Got WIRE_HSMD_VALIDATE_COMMITMENT_TX
2022-12-10T20:47:50.087Z DEBUG   hsmd: Client: Received message 35 from client
2022-12-10T20:47:50.089Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-hsmd: Got WIRE_HSMD_SIGN_REMOTE_COMMITMENT_TX
2022-12-10T20:47:50.089Z DEBUG   hsmd: Client: Received message 19 from client
2022-12-10T20:47:50.089Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-chan#1: Got opening_fundee_finish_response
2022-12-10T20:47:50.091Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-chan#1: Watching funding tx 8ec4ee4dd01e079a1e79e74dbd578d9b5ac89705141dbac2f9733bb6d93f1fe5
2022-12-10T20:47:50.093Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: pid 32345, msgfd 70
2022-12-10T20:47:50.093Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-chan#1: Waiting for funding confirmations
2022-12-10T20:47:50.093Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-chan#1: Ignoring fee limits!
2022-12-10T20:47:50.093Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-openingd-chan#1: Status closed, but not exited. Killing
2022-12-10T20:47:50.095Z DEBUG   hsmd: new_client: 1
2022-12-10T20:47:50.097Z DEBUG   lightningd: ... feerate estimate for opening hit floor 253
2022-12-10T20:47:50.097Z DEBUG   lightningd: ... feerate estimate for mutual_close hit floor 253
2022-12-10T20:47:50.097Z DEBUG   lightningd: ... feerate estimate for unilateral_close hit floor 253
2022-12-10T20:47:50.097Z DEBUG   lightningd: ... feerate estimate for delayed_to_us hit floor 253
2022-12-10T20:47:50.097Z DEBUG   lightningd: ... feerate estimate for htlc_resolution hit floor 253
2022-12-10T20:47:50.097Z DEBUG   lightningd: ... feerate estimate for penalty hit floor 253
2022-12-10T20:47:50.097Z DEBUG   lightningd: ... polled feerate estimate for min_acceptable (125) smoothed to 250 (alpha=0.02)
2022-12-10T20:47:50.097Z DEBUG   lightningd: ... feerate estimate for min_acceptable hit floor 253
2022-12-10T20:47:50.098Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: option_static_remotekey = 1, option_anchor_outputs = 0
2022-12-10T20:47:50.098Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: init REMOTE: remote_per_commit = 02518a5db9ad66bada347cc4bc69dbd3eacca70042a7c7b2102e00cdbaa51ae75c, old_remote_per_commit = 02518a5db9ad66bada347cc4bc69dbd3eacca70042a7c7b2102e00cdbaa51ae75c next_idx_local = 1 next_idx_remote = 1 revocations_received = 0 feerates { RCVD_ADD_ACK_REVOCATION:253 } range 253-4294967295 blockheights { RCVD_ADD_ACK_REVOCATION:0 }, our current 115
2022-12-10T20:47:50.098Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:47:50.098Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:47:50.098Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: peer_out WIRE_FUNDING_SIGNED
2022-12-10T20:47:50.098Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: billboard: Funding needs 0 more confirmations to be ready.
2022-12-10T20:47:50.098Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: channel_ready: sending commit index 1: 02d7fdc7447d3885b8a4ec23f2da7f9291ceeeeaecbf8c7c215ddbdaa992cdf5ec
2022-12-10T20:47:50.099Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-hsmd: Got WIRE_HSMD_GET_PER_COMMITMENT_POINT
2022-12-10T20:47:50.099Z DEBUG   hsmd: Client: Received message 18 from client
2022-12-10T20:47:50.099Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: peer_out WIRE_CHANNEL_READY
2022-12-10T20:47:50.099Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: billboard: We've confirmed channel ready, they haven't yet.
2022-12-10T20:47:50.110Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: peer_in WIRE_CHANNEL_READY
2022-12-10T20:47:50.110Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: Peer told us that they'll use alias=7054100x15544350x62801 for this channel
2022-12-10T20:47:50.110Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-chan#1: Got channel_ready
2022-12-10T20:47:50.111Z INFO    02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-chan#1: State changed from CHANNELD_AWAITING_LOCKIN to CHANNELD_NORMAL
2022-12-10T20:47:50.111Z DEBUG   lightningd: update_feerates: feerate = 253, min=253, max=4294967295, penalty=253
2022-12-10T20:47:50.111Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-chan#1: attempting update blockheight e51f3fd9b63b73f9c2ba1d140597c85a9b8d57bd4de7791e9a071ed04deec48f
2022-12-10T20:47:50.113Z DEBUG   plugin-funder: Cleaning up datastore for channel_id e51f3fd9b63b73f9c2ba1d140597c85a9b8d57bd4de7791e9a071ed04deec48f
2022-12-10T20:47:50.113Z DEBUG   02a428a7fbfecfac8b7e252813fa240a1203895cb0cb4ad13192ca2f39c9c63102-channeld-chan#1: billboard: Channel ready for use.

Dec 10 '22 21:12 JssDWt

lightning lightning copied to clipboard

zero conf channel stuck in CHANNELD_AWAITING_LOCKIN sometimes: Owning subdaemon channeld died

Issue and Steps to Reproduce

Failing flow

Channel funder

Accepting peer

Succesful flow

Channel funder

Accepting peer

lightning
lightning copied to clipboard