`test_cln` is flaky now

[tnull]

After #524 we now started seeing test_cln failing with the following message, which is curious, as it seems to be working as expected locally:

thread 'test_cln' panicked at tests/integration_tests_cln.rs:89:23:
node got unexpected event!: ChannelClosed { channel_id: d7011b89329aa3686e46769cedede561a406fd764419b8ba02cbbdb9d6b89eb9, user_channel_id: UserChannelId(218640611731153854047642377166051042969), counterparty_node_id: Some(PublicKey(29975387f8f71e43d7355942980f73450be266cc424d3adca4fc840b72d176440f36b19f80245464c148c4545065cfd16c5130c8ded025a8c05267374e0ca6c4)), reason: Some(DisconnectedPeer) }
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace


failures:
    test_cln

[Camillarhi]

Hi @tnull,

I wanted to note that this issue is also affecting my PR (#519). I ran the tests locally using the same Docker Compose setup (docker-compose-cln.yml) and they passed successfully, which suggests the problem might be specific to the CI environment.

If there’s anything I can do to help debug this further, let me know!

[Camillarhi]

Hi @tnull,

I wanted to note that this issue is also affecting my PR (#519). I ran the tests locally using the same Docker Compose setup (docker-compose-cln.yml) and they passed successfully, which suggests the problem might be specific to the CI environment.

If there’s anything I can do to help debug this further, let me know!

Hi @tnull ,

I rebased my branch onto the latest dev (including changes from #524), and now test_cln passes both locally and in CI. This suggests the issue was likely caused by an outdated branch state.

It seems resolved for now, but let me know if anything else needs to be checked!

[enigbe]

I've tried to reproduce the CI errors locally. Each test run passes, but the socat logs consistently show "Connection reset by peer" warnings and socket errors (see streamlined lines below). Could these be contributing to the CI failures, even though socat exits with status 0?

I'm unsure how to interpret this—any pointers on debugging this further would be appreciated.

2025/05/27 16:25:20 socat[1908694] W read(6, 0x564ad81f6000, 8192): Connection reset by peer
2025/05/27 16:25:20 socat[1908694] N socket 1 to socket 2 is in error
...
2025/05/27 16:25:59 socat[1909070] W read(6, 0x564ad81f6000, 8192): Connection reset by peer
2025/05/27 16:25:59 socat[1909070] N socket 1 to socket 2 is in error
...
2025/05/27 16:26:12 socat[1909165] W read(6, 0x564ad81f6000, 8192): Connection reset by peer
2025/05/27 16:26:12 socat[1909165] N socket 1 to socket 2 is in error
...
2025/05/27 16:26:23 socat[1909248] W read(6, 0x564ad81f6000, 8192): Connection reset by peer
2025/05/27 16:26:23 socat[1909248] N socket 1 to socket 2 is in error
...
2025/05/27 16:26:23 socat[1909248] N exiting with status 0

Update

I introduced a 1 second delay in between opening a channel and checking for ChannelPending event and the CI passed on my local repository.

I am uncertain about this but in the CI environment, I think cln disconnects when the channel is being opened but the delay gives the connection manager time to re-connect if necessary.

[moisesPompilio]

In Core Lightning (CLN) v23.08, there's an assertion that checks if chan->first_blocknum is set when saving the channel. If not, CLN crashes with a fatal signal.

This issue occurs in our integration tests with ldk-node, which interacts with CLN. The crash likely happens because CLN does not update its block height in time during the fast startup and block mining process.

Local test logs from CLN show:

2025-06-30T14:48:08.883Z INFO    lightningd: Server started with public key 0386e74338d3ca6880c4c5a193d13d6814c48e5e2b0ed99bb1f03fa03a803989ac, alias JUNIORAUTO and lightningd v23.08-modded

Assertion failed: chan->first_blocknum (wallet/wallet.c: wallet_channel_save: 2112)

lightningd: FATAL SIGNAL 6 (version v23.08-modded)

0x55bae75dbdcb send_backtrace

common/daemon.c:33

0x55bae75dbe53 crashdump

common/daemon.c:75

2025-06-30T14:48:37.892Z **BROKEN** lightningd: FATAL SIGNAL 6 (version v23.08-modded)

2025-06-30T14:48:37.892Z **BROKEN** lightningd: backtrace: common/daemon.c:38 (send_backtrace) 0x55bae75dbe13

2025-06-30T14:48:37.892Z **BROKEN** lightningd: backtrace: common/daemon.c:75 (crashdump) 0x55bae75dbe53

2025-06-30T14:48:37.892Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x7fd535c61ac9

0x7fd535c61ac9 ???

???:0

To investigate, a println! was added to print CLN's block height before the crash. CI logs from ldk-node showed:

[CLN] Node block height: 0

thread 'test_cln' panicked at tests/integration_tests_cln.rs:89:23:
node got unexpected event!: ChannelClosed { channel_id: b116349fbdee203c8f7feae1cccf603fee280bc87dbec2320e31a231876d453c, user_channel_id: UserChannelId(123258951723483688250285599732121933265), counterparty_node_id: Some(PublicKey(5a8363b4a4f32241ddd4e58845efc6a2a23d5d0e741bae999edb1689694f724a2a47f20ddaf523454c2adc9172824afbea80f18fdc5f47d35802f33e00576ff6)), reason: Some(DisconnectedPeer) }
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
test test_cln ... FAILED

This confirms that CLN crashed before completing the channel open, and ldk-node received a disconnect event as a result.