lightningd: early exit of plugin causes assertion fail

[SimonVrouwe]

Not a big issue, but to demonstrate that the io_break checks can be improved.

A simple example, modify cowsay.sh so that it exits right before the init reply:

#! /bin/sh

maybe_cowsay()
{
    cowsay || cat <<EOF
 _________________________________
< Please install 'cowsay' program >
 ---------------------------------
        \\   ^__^
         \\  (xx)\\_______
            (__)\\       )\\/\\
             U  ||----w |
                ||     ||
EOF
}

# Eg. {"jsonrpc":"2.0","id":2,"method":"getmanifest","params":{}}\n\n
read -r JSON
read -r _
id=$(echo "$JSON" | sed 's/.*"id" *: *\([0-9]*\),.*/\1/')

echo '{"jsonrpc":"2.0","id":'"$id"',"result":{"dynamic":true,"options":[],"rpcmethods":[{"name":"cowsay","usage":"<string>","description":"Have a cow, man!"}]}}'

# Eg. {"jsonrpc":"2.0","id":5,"method":"init","params":{"options":{},"configuration":{"lightning-dir":"/home/rusty/.lightning","rpc-file":"lightning-rpc","startup":false}}}\n\n
read -r JSON
read -r _
exit 1
id=$(echo "$JSON" | sed 's/.*"id" *: *\([0-9]*\),.*/\1/')

echo '{"jsonrpc":"2.0","id":'"$id"',"result":{}}'

and make it an important-plugin in config, then starting lightningd fails with assertion error:

2021-11-27T11:33:46.013Z INFO    plugin-cowsay.sh: Killing plugin: exited before replying to init
2021-11-27T11:33:46.013Z **BROKEN** plugin-cowsay.sh: Plugin marked as important, shutting down lightningd!
2021-11-27T11:33:46.013Z INFO    lightningd: --------------------------------------------------
2021-11-27T11:33:46.013Z INFO    lightningd: Server started with public key 035bb05c742fdc70ae5620435ea7a2cd8984644c7bc27b4b919d1bc4fbca76be08, alias CLtest (color #035bb0) and lightningd v0.10.2-40-ga9e261f
2021-11-27T11:33:46.013Z DEBUG   connectd: REPLY WIRE_CONNECTD_ACTIVATE_REPLY with 0 fds
lightningd: lightningd/lightningd.c:1169: main: Assertion `io_loop_ret == ld' failed.
lightningd: FATAL SIGNAL 6 (version v0.10.2-40-ga9e261f)

This is because destroy_plugin calls

lightning/lightningd/plugin.c

Line 208 in c1f534a

lightningd_exit(p->plugins->ld, 1);

calls io_break

lightning/lightningd/lightningd.c

Lines 838 to 842 in c1f534a

	void lightningd_exit(struct lightningd *ld, int exit_code)
	{
	ld->exit_code = tal(ld, int);
	*ld->exit_code = exit_code;
	io_break(ld);

Which makes the next (and subsequent?) io_loop break-immediately and eventually the main event loop breaks on io_break value from one of the previous loops. These things are hard to debug and I think some extra checks could be added, such as io_break returning more specific pointer which can be checked when io_loop returns.

[SimonVrouwe]

Nice that this issue has been addresses by 4c97a07 in #5281
Every io_break return value is now (assert) checked followed by a log_debug message where in the code it happened.