Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

clightning: add shutdown hook for plugin #318

Merged
merged 3 commits into from
Nov 19, 2024
Merged

clightning: add shutdown hook for plugin #318

merged 3 commits into from
Nov 19, 2024

Conversation

YusukeShimizu
Copy link
Contributor

@YusukeShimizu YusukeShimizu commented Sep 23, 2024 •
edited
Loading

Introduces a shutdown hook to the clightning plugin, ensuring that the plugin is gracefully stopped when c-lightning shuts down.

fixes: #307

@YusukeShimizu YusukeShimizu mentioned this pull request Sep 23, 2024
Closed
@YusukeShimizu YusukeShimizu marked this pull request as ready for review September 24, 2024 11:16
@grubles
Copy link
Collaborator

grubles commented Oct 30, 2024

I'm getting this when shutting down CLN (v24.08.2):

2024-10-30T14:42:07.568Z UNUSUAL lightningd: JSON-RPC shutdown
2024-10-30T14:42:07.569Z DEBUG   lightningd: io_break: start_json_stream
2024-10-30T14:42:07.569Z DEBUG   lightningd: io_loop_with_timers: main
2024-10-30T14:42:07.569Z DEBUG   connectd: REPLY WIRE_CONNECTD_START_SHUTDOWN_REPLY with 0 fds
2024-10-30T14:42:07.569Z DEBUG   lightningd: io_break: connectd_start_shutdown_reply
...
2024-10-30T14:42:37.593Z DEBUG   lightningd: peerswap: failed to self-terminate in time, killing.
2024-10-30T14:42:37.594Z DEBUG   lightningd: io_break: destroy_plugin
2024-10-30T14:42:37.594Z DEBUG   lightningd: Command returned result after jcon close
2024-10-30T14:42:37.595Z DEBUG   connectd: Shutting down
2024-10-30T14:42:37.597Z DEBUG   gossipd: Shutting down
2024-10-30T14:42:37.598Z DEBUG   hsmd: Shutting down

Is this the intended behavior?

@YusukeShimizu
Copy link
Contributor Author

The behavior seems to be different from what was expected.
It should terminate with logs like the ones below.
I added an E2E test to verify such behavior.
43b1d7d

clightning-1: 2024-11-10T00:53:24.810Z UNUSUAL lightningd: JSON-RPC shutdown
clightning-1: 2024-11-10T00:53:24.810Z DEBUG   lightningd: io_break: start_json_stream
2024-11-10T00:53:24.810Z DEBUG   lightningd: io_loop_with_timers: main
clightning-1: 2024-11-10T00:53:24.810Z DEBUG   connectd: REPLY WIRE_CONNECTD_START_SHUTDOWN_REPLY with 0 fds
2024-11-10T00:53:24.810Z DEBUG   lightningd: io_break: connectd_start_shutdown_reply
clightning-1: 2024-11-10T00:53:24.810Z DEBUG   03bed3ea4df3506aeacad110dd6c15d9a14e2ea9e9456fb84d07f2f291d31bf8d1-channeld-chan#1: Status closed, but not exited. Killing
clightning-1: 2024-11-10T00:53:24.810Z INFO    03bed3ea4df3506aeacad110dd6c15d9a14e2ea9e9456fb84d07f2f291d31bf8d1-chan#1: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (9)
clightning-1: 2024-11-10T00:53:24.811Z DEBUG   plugin-chanbackup: Killing plugin: exited during normal operation
2024-11-10T00:53:24.811Z DEBUG   plugin-bcli: Killing plugin: exited during normal operation
2024-11-10T00:53:24.812Z DEBUG   plugin-pay: Killing plugin: exited during normal operation
2024-11-10T00:53:24.812Z DEBUG   plugin-autoclean: Killing plugin: exited during normal operation
2024-11-10T00:53:24.812Z DEBUG   plugin-recover: Killing plugin: exited during normal operation
2024-11-10T00:53:24.813Z DEBUG   plugin-spenderp: Killing plugin: exited during normal operation
2024-11-10T00:53:24.813Z DEBUG   plugin-commando: Killing plugin: exited during normal operation
2024-11-10T00:53:24.813Z DEBUG   plugin-txprepare: Killing plugin: exited during normal operation
clightning-1: 2024-11-10T00:53:24.813Z DEBUG   plugin-funder: Killing plugin: exited during normal operation
clightning-1: 2024-11-10T00:53:24.813Z DEBUG   plugin-topology: Killing plugin: exited during normal operation
clightning-1: 2024-11-10T00:53:24.813Z DEBUG   plugin-keysend: Killing plugin: exited during normal operation
clightning-1: 2024-11-10T00:53:24.813Z DEBUG   plugin-offers: Killing plugin: exited during normal operation
clightning-1: 2024-11-10T00:53:24.814Z DEBUG   plugin-bookkeeper: Killing plugin: exited during normal operation
clightning-1: 2024-11-10T00:53:24.814Z DEBUG   plugin-sql: Killing plugin: exited during normal operation
clightning-1: 2024-11-10T00:53:24.814Z DEBUG   plugin-cln-askrene: Killing plugin: exited during normal operation
clightning-1: 2024-11-10T00:53:24.814Z DEBUG   plugin-cln-renepay: Killing plugin: exited during normal operation
clightning-1: 2024-11-10T00:53:24.814Z DEBUG   plugin-recklessrpc: Killing plugin: exited during normal operation
clightning-1: 2024-11-10T00:53:32.199Z DEBUG   03bed3ea4df3506aeacad110dd6c15d9a14e2ea9e9456fb84d07f2f291d31bf8d1-gossipd: seeker: startup peer finished
2024-11-10T00:53:32.199Z DEBUG   03bed3ea4df3506aeacad110dd6c15d9a14e2ea9e9456fb84d07f2f291d31bf8d1-gossipd: seeker: state = PROBING_SCIDS Seeking scids 1 - 112
2024-11-10T00:53:32.199Z DEBUG   03bed3ea4df3506aeacad110dd6c15d9a14e2ea9e9456fb84d07f2f291d31bf8d1-gossipd: sending query_channel_range for blocks 1+112
2024-11-10T00:53:32.199Z DEBUG   03bed3ea4df3506aeacad110dd6c15d9a14e2ea9e9456fb84d07f2f291d31bf8d1-connectd: peer_out WIRE_QUERY_CHANNEL_RANGE
clightning-1: 2024-11-10T00:53:32.199Z DEBUG   03bed3ea4df3506aeacad110dd6c15d9a14e2ea9e9456fb84d07f2f291d31bf8d1-gossipd: reply_channel_range 1+112 (of 1+112) 1 scids
2024-11-10T00:53:32.199Z DEBUG   gossipd: seeker: state = NORMAL No unannounced nodes
clightning-1: 2024-11-10T00:53:33.474Z DEBUG   03bed3ea4df3506aeacad110dd6c15d9a14e2ea9e9456fb84d07f2f291d31bf8d1-connectd: peer_out INVALID 42085
2024-11-10T00:53:33.474Z DEBUG   03bed3ea4df3506aeacad110dd6c15d9a14e2ea9e9456fb84d07f2f291d31bf8d1-connectd: peer_in INVALID 42085
clightning-1: 2024-11-10T00:53:33.476Z DEBUG   plugin-peerswap: Killing plugin: exited during normal operation
2024-11-10T00:53:33.476Z DEBUG   lightningd: io_break: destroy_plugin
clightning-1: 2024-11-10T00:53:33.476Z DEBUG   lightningd: Command returned result after jcon close
clightning-1: 2024-11-10T00:53:33.476Z DEBUG   connectd: Shutting down
clightning-1: 2024-11-10T00:53:33.477Z DEBUG   gossipd: Shutting down
clightning-1: 2024-11-10T00:53:33.477Z DEBUG   hsmd: Shutting down

@grubles
Copy link
Collaborator

grubles commented Nov 13, 2024 •
edited
Loading

Hmm peerswap is now exiting at startup thinking deprecated APIs are disabled if I'm using CLN master:

2024-11-13T14:17:20.121Z INFO    plugin-peerswap: WARNING: allow-deprecated-apis=false detected in CLN config. Exiting. More info: https://github.com/ElementsProject/peerswap/issues/232
2024-11-13T14:17:21.122Z INFO    plugin-peerswap: Killing plugin: exited during normal operation

@grubles
Copy link
Collaborator

grubles commented Nov 13, 2024

Using CLN v24.08.2, I'm getting the same self-termination message as before:

2024-11-13T17:33:33.607Z DEBUG   lightningd: peerswap: failed to self-terminate in time, killing.

@YusukeShimizu
clightning: add shutdown hook for plugin
22cdafa 
Introduces a shutdown hook to the clightning plugin, ensuring
that the plugin is gracefully stopped when c-lightning shuts down.

* Subscribe to the 'shutdown' event.
* Updated glightning dependency to include the 'shutdown' event.
@YusukeShimizu
fixup! clightning: add shutdown hook for plugin
e2095fc
@YusukeShimizu YusukeShimizu force-pushed the plugin-shutdown-subscription branch 2 times, most recently from 547f73e to e2095fc Compare November 15, 2024 08:24
@YusukeShimizu
Copy link
Contributor Author

#330 updated the nix package and was tested with v24.08.02, but it seems the issue does not reproduce.
There might be a specific sequence when the issue occurs.

Regarding the deprecated APIs issue, I rebased on the master branch as the fix in the following PR might have an impact:
#321

@YusukeShimizu
Copy link
Contributor Author

There was a case where the shutdown hook was not executed when the standard input with cln remained in glightning.

I have modified it to process messages asynchronously, allowing us to stop listening when a shutdown signal is received.

Although I am not certain that this is the cause of the issue, this is the only problem I can currently think of.
Could you please try again?

@grubles
Copy link
Collaborator

grubles commented Nov 19, 2024

With the latest commit, peerswap exits instantly while CLN is shutting down. Tested ACK 6dd09b7

@grubles grubles merged commit 64fca6c into master Nov 19, 2024
8 checks passed
@YusukeShimizu YusukeShimizu mentioned this pull request Nov 20, 2024
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

CLN plugin does not gracefully exit
2 participants
@YusukeShimizu @grubles