From 01c0e39218eeda3fa1541530e77690f03d599285 Mon Sep 17 00:00:00 2001 From: Michael Schmoock Date: Tue, 8 Sep 2020 16:11:05 +0200 Subject: [PATCH 1/5] feat: adds channel_state_changed notification This notification will be raised whenever a channel state changes. The payload includes the channel and peer identifiers and the old and the new state. Example payload: ``` { "channel_state_changed": { "peer_id": "03bc9337c7a28bb784d67742ebedd30a93bacdf7e4ca16436ef3798000242b2251", "channel_id": "a2d0851832f0e30a0cf778a826d72f077ca86b69f72677e0267f23f63a0599b4", "short_channel_id" : "561820x1020x1", "old_state": "CHANNELD_NORMAL", "new_state": "AWAITING_UNILATERAL" } } ``` Changelog-Added: Plugins: channel_state_changed notification --- lightningd/channel.c | 12 +++++++++ lightningd/notification.c | 45 +++++++++++++++++++++++++++++++++ lightningd/notification.h | 9 +++++++ wallet/db_postgres_sqlgen.c | 2 +- wallet/db_sqlite3_sqlgen.c | 2 +- wallet/statements_gettextgen.po | 4 +-- wallet/test/run-wallet.c | 8 ++++++ 7 files changed, 78 insertions(+), 4 deletions(-) diff --git a/lightningd/channel.c b/lightningd/channel.c index 47d819f38765..0d8fa436b6b2 100644 --- a/lightningd/channel.c +++ b/lightningd/channel.c @@ -18,6 +18,7 @@ #include #include #include +#include #include #include #include @@ -384,6 +385,8 @@ void channel_set_state(struct channel *channel, enum channel_state old_state, enum channel_state state) { + struct channel_id cid; + log_info(channel->log, "State changed from %s to %s", channel_state_name(channel), channel_state_str(state)); if (channel->state != old_state) @@ -394,6 +397,15 @@ void channel_set_state(struct channel *channel, /* TODO(cdecker) Selectively save updated fields to DB */ wallet_channel_save(channel->peer->ld->wallet, channel); + + /* plugin notification channel_state_changed */ + derive_channel_id(&cid, &channel->funding_txid, channel->funding_outnum); + notify_channel_state_changed(channel->peer->ld, + &channel->peer->id, + &cid, + channel->scid, + old_state, + state); } void channel_fail_permanent(struct channel *channel, const char *fmt, ...) diff --git a/lightningd/notification.c b/lightningd/notification.c index 377da2c131a5..e25ed2144199 100644 --- a/lightningd/notification.c +++ b/lightningd/notification.c @@ -210,6 +210,51 @@ void notify_channel_opened(struct lightningd *ld, struct node_id *node_id, plugins_notify(ld->plugins, take(n)); } +static void channel_state_changed_notification_serialize(struct json_stream *stream, + struct node_id *peer_id, + struct channel_id *cid, + struct short_channel_id *scid, + enum channel_state old_state, + enum channel_state new_state) +{ + json_object_start(stream, "channel_state_changed"); + json_add_node_id(stream, "peer_id", peer_id); + json_add_string(stream, "channel_id", + type_to_string(tmpctx, struct channel_id, cid)); + if (scid) + json_add_short_channel_id(stream, "short_channel_id", scid); + else + json_add_null(stream, "short_channel_id"); + json_add_string(stream, "old_state", channel_state_str(old_state)); + json_add_string(stream, "new_state", channel_state_str(new_state)); + json_object_end(stream); +} + + +REGISTER_NOTIFICATION(channel_state_changed, + channel_state_changed_notification_serialize) + +void notify_channel_state_changed(struct lightningd *ld, + struct node_id *peer_id, + struct channel_id *cid, + struct short_channel_id *scid, + enum channel_state old_state, + enum channel_state new_state) +{ + void (*serialize)(struct json_stream *, + struct node_id *, + struct channel_id *, + struct short_channel_id *, + enum channel_state, + enum channel_state) = channel_state_changed_notification_gen.serialize; + + struct jsonrpc_notification *n + = jsonrpc_notification_start(NULL, channel_state_changed_notification_gen.topic); + serialize(n->stream, peer_id, cid, scid, old_state, new_state); + jsonrpc_notification_end(n); + plugins_notify(ld->plugins, take(n)); +} + static void forward_event_notification_serialize(struct json_stream *stream, const struct htlc_in *in, const struct short_channel_id *scid_out, diff --git a/lightningd/notification.h b/lightningd/notification.h index 94047988708e..000c76d281fb 100644 --- a/lightningd/notification.h +++ b/lightningd/notification.h @@ -7,9 +7,11 @@ #include #include #include +#include #include #include #include +#include #include #include #include @@ -55,6 +57,13 @@ void notify_channel_opened(struct lightningd *ld, struct node_id *node_id, struct amount_sat *funding_sat, struct bitcoin_txid *funding_txid, bool *funding_locked); +void notify_channel_state_changed(struct lightningd *ld, + struct node_id *peer_id, + struct channel_id *cid, + struct short_channel_id *scid, + enum channel_state old_state, + enum channel_state new_state); + void notify_forward_event(struct lightningd *ld, const struct htlc_in *in, /* May be NULL if we don't know. */ diff --git a/wallet/db_postgres_sqlgen.c b/wallet/db_postgres_sqlgen.c index a5ad0885bd5e..59054dd69ed3 100644 --- a/wallet/db_postgres_sqlgen.c +++ b/wallet/db_postgres_sqlgen.c @@ -1648,4 +1648,4 @@ struct db_query db_postgres_queries[] = { #endif /* LIGHTNINGD_WALLET_GEN_DB_POSTGRES */ -// SHA256STAMP:e55a8febb74330a9167e8498b26e556609d95b7ca6ef984da1fa200e53e36a7e +// SHA256STAMP:4c9787464f33fe9bfd209efbd84daebeb5584d52daa1d83f4c34f9a0a6108b46 diff --git a/wallet/db_sqlite3_sqlgen.c b/wallet/db_sqlite3_sqlgen.c index c3b0c0fc2d28..d8dbc441ecd2 100644 --- a/wallet/db_sqlite3_sqlgen.c +++ b/wallet/db_sqlite3_sqlgen.c @@ -1648,4 +1648,4 @@ struct db_query db_sqlite3_queries[] = { #endif /* LIGHTNINGD_WALLET_GEN_DB_SQLITE3 */ -// SHA256STAMP:e55a8febb74330a9167e8498b26e556609d95b7ca6ef984da1fa200e53e36a7e +// SHA256STAMP:4c9787464f33fe9bfd209efbd84daebeb5584d52daa1d83f4c34f9a0a6108b46 diff --git a/wallet/statements_gettextgen.po b/wallet/statements_gettextgen.po index 896e00e9cab4..09d558dabb8d 100644 --- a/wallet/statements_gettextgen.po +++ b/wallet/statements_gettextgen.po @@ -1082,7 +1082,7 @@ msgstr "" msgid "not a valid SQL statement" msgstr "" -#: wallet/test/run-wallet.c:1351 +#: wallet/test/run-wallet.c:1359 msgid "INSERT INTO channels (id) VALUES (1);" msgstr "" -# SHA256STAMP:de15ae770286fe050f7b2d712bcc2a3311a8737e920353bb8c7d8dbf0188db69 +# SHA256STAMP:108fcc46e6fa6e190b27773161a9c6bf9a83cb25e9d3164fa40e9de9e6f98644 diff --git a/wallet/test/run-wallet.c b/wallet/test/run-wallet.c index a6834fed938f..13bbc4e60fce 100644 --- a/wallet/test/run-wallet.c +++ b/wallet/test/run-wallet.c @@ -428,6 +428,14 @@ void notify_chain_mvt(struct lightningd *ld UNNEEDED, const struct chain_coin_mv /* Generated stub for notify_channel_mvt */ void notify_channel_mvt(struct lightningd *ld UNNEEDED, const struct channel_coin_mvt *mvt UNNEEDED) { fprintf(stderr, "notify_channel_mvt called!\n"); abort(); } +/* Generated stub for notify_channel_state_changed */ +void notify_channel_state_changed(struct lightningd *ld UNNEEDED, + struct node_id *peer_id UNNEEDED, + struct channel_id *cid UNNEEDED, + struct short_channel_id *scid UNNEEDED, + enum channel_state old_state UNNEEDED, + enum channel_state new_state UNNEEDED) +{ fprintf(stderr, "notify_channel_state_changed called!\n"); abort(); } /* Generated stub for notify_connect */ void notify_connect(struct lightningd *ld UNNEEDED, struct node_id *nodeid UNNEEDED, struct wireaddr_internal *addr UNNEEDED) From 58dd90c7c5f10b4229d3e08508b678f074ef8b55 Mon Sep 17 00:00:00 2001 From: Michael Schmoock Date: Tue, 8 Sep 2020 16:18:53 +0200 Subject: [PATCH 2/5] doc: plugin channel_state_changed --- doc/PLUGINS.md | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) diff --git a/doc/PLUGINS.md b/doc/PLUGINS.md index a6fa2332ec76..0cf22eb98ec2 100644 --- a/doc/PLUGINS.md +++ b/doc/PLUGINS.md @@ -322,6 +322,24 @@ into a block. } ``` +### `channel_state_changed` + +A notification for topic `channel_state_changed` is sent every time a channel +changes its state. The notification includes the peer and channel ids as well +as the old and the new channel states. + +```json +{ + "channel_state_changed": { + "peer_id": "03bc9337c7a28bb784d67742ebedd30a93bacdf7e4ca16436ef3798000242b2251", + "channel_id": "a2d0851832f0e30a0cf778a826d72f077ca86b69f72677e0267f23f63a0599b4", + "short_channel_id" : "561820x1020x1", + "old_state": "CHANNELD_NORMAL", + "new_state": "CHANNELD_SHUTTING_DOWN" + } +} +``` + ### `connect` A notification for topic `connect` is sent every time a new connection From 3767e29aee398b977751ef4db541d16146353956 Mon Sep 17 00:00:00 2001 From: Michael Schmoock Date: Tue, 8 Sep 2020 18:15:16 +0200 Subject: [PATCH 3/5] pyln-testing: add get_channel_id helper --- contrib/pyln-testing/pyln/testing/utils.py | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/contrib/pyln-testing/pyln/testing/utils.py b/contrib/pyln-testing/pyln/testing/utils.py index 0b08e2d13397..48b0b8a6dd87 100644 --- a/contrib/pyln-testing/pyln/testing/utils.py +++ b/contrib/pyln-testing/pyln/testing/utils.py @@ -800,6 +800,15 @@ def get_channel_scid(self, other): channel = peers[0]['channels'][0] return channel['short_channel_id'] + def get_channel_id(self, other): + """Get the channel_id for the channel to the other node. + """ + peers = self.rpc.listpeers(other.info['id'])['peers'] + if not peers or 'channels' not in peers[0]: + return None + channel = peers[0]['channels'][0] + return channel['channel_id'] + def is_channel_active(self, chanid): channels = self.rpc.listchannels(chanid)['channels'] active = [(c['short_channel_id'], c['channel_flags']) for c in channels if c['active']] From 287f60651bb7cef02f2e1d7209e9b904c30d00c9 Mon Sep 17 00:00:00 2001 From: Michael Schmoock Date: Tue, 8 Sep 2020 18:16:04 +0200 Subject: [PATCH 4/5] test: plugin channel_state_changed notification --- tests/plugins/misc_notifications.py | 7 +- tests/test_plugin.py | 125 ++++++++++++++++++++++++++++ 2 files changed, 131 insertions(+), 1 deletion(-) diff --git a/tests/plugins/misc_notifications.py b/tests/plugins/misc_notifications.py index 79d416abb9f3..ac3af645c7ac 100755 --- a/tests/plugins/misc_notifications.py +++ b/tests/plugins/misc_notifications.py @@ -15,11 +15,16 @@ def init(plugin, options, configuration): @plugin.subscribe("channel_opened") -def channel_opened(plugin, channel_opened): +def channel_opened(plugin, channel_opened, **kwargs): plugin.log("A channel was opened to us by {}, with an amount" " of {} and the following funding transaction id: {}" .format(channel_opened["id"], channel_opened["amount"], channel_opened["funding_txid"])) +@plugin.subscribe("channel_state_changed") +def channel_state_changed(plugin, channel_state_changed, **kwargs): + plugin.log("channel_state_changed {}".format(channel_state_changed)) + + plugin.run() diff --git a/tests/test_plugin.py b/tests/test_plugin.py index f98b5dfdbe2e..8d647e9654e2 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -11,6 +11,7 @@ check_coin_moves, first_channel_id, check_coin_moves_idx, EXPERIMENTAL_FEATURES ) +import ast import json import os import pytest @@ -631,6 +632,130 @@ def test_openchannel_hook_chaining(node_factory, bitcoind): assert l2.daemon.wait_for_log(hook_msg + "reject on principle") +def test_channel_state_changed(node_factory, bitcoind): + opts = [{}, {"plugin": os.path.join(os.getcwd(), "tests/plugins/misc_notifications.py")}] + l1, l2 = node_factory.line_graph(2, opts=opts) + + peer_id = l1.rpc.getinfo()["id"] + cid = l1.get_channel_id(l2) + scid = l1.get_channel_scid(l2) + + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "CHANNELD_AWAITING_LOCKIN") + assert(event['new_state'] == "CHANNELD_NORMAL") + + # close channel and look for stateful events + l1.rpc.close(scid) + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "CHANNELD_NORMAL") + assert(event['new_state'] == "CHANNELD_SHUTTING_DOWN") + + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "CHANNELD_SHUTTING_DOWN") + assert(event['new_state'] == "CLOSINGD_SIGEXCHANGE") + + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "CLOSINGD_SIGEXCHANGE") + assert(event['new_state'] == "CLOSINGD_COMPLETE") + + bitcoind.generate_block(100) # so it gets settled + + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "CLOSINGD_COMPLETE") + assert(event['new_state'] == "FUNDING_SPEND_SEEN") + + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "FUNDING_SPEND_SEEN") + assert(event['new_state'] == "ONCHAIN") + + +def test_channel_state_changed_unilateral(node_factory, bitcoind): + opts = [{}, {"plugin": os.path.join(os.getcwd(), "tests/plugins/misc_notifications.py")}] + l1, l2 = node_factory.line_graph(2, opts=opts) + + peer_id = l1.rpc.getinfo()["id"] + cid = l1.get_channel_id(l2) + scid = l1.get_channel_scid(l2) + + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "CHANNELD_AWAITING_LOCKIN") + assert(event['new_state'] == "CHANNELD_NORMAL") + + # close channel unilaterally and look for stateful events + l1.rpc.stop() + wait_for(lambda: not only_one(l2.rpc.listpeers()['peers'])['connected']) + l2.rpc.close(scid, 1) # 1sec timeout + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "CHANNELD_NORMAL") + assert(event['new_state'] == "CHANNELD_SHUTTING_DOWN") + + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "CHANNELD_SHUTTING_DOWN") + assert(event['new_state'] == "AWAITING_UNILATERAL") + + bitcoind.generate_block(100) # so it gets settled + + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "AWAITING_UNILATERAL") # this actually happens + assert(event['new_state'] == "AWAITING_UNILATERAL") # note: same states + + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "AWAITING_UNILATERAL") + assert(event['new_state'] == "FUNDING_SPEND_SEEN") + + msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") + event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) + assert(event['peer_id'] == peer_id) + assert(event['channel_id'] == cid) + assert(event['short_channel_id'] == scid) + assert(event['old_state'] == "FUNDING_SPEND_SEEN") + assert(event['new_state'] == "ONCHAIN") + + @unittest.skipIf(not DEVELOPER, "without DEVELOPER=1, gossip v slow") def test_htlc_accepted_hook_fail(node_factory): """Send payments from l1 to l2, but l2 just declines everything. From 6fc4f2f63ca43b645f3429f82f310f1e117201c5 Mon Sep 17 00:00:00 2001 From: Michael Schmoock Date: Wed, 9 Sep 2020 13:28:45 +0200 Subject: [PATCH 5/5] fix: suppress duplicated channel_state_changed events --- lightningd/channel.c | 16 +++++++++------- tests/test_plugin.py | 8 -------- 2 files changed, 9 insertions(+), 15 deletions(-) diff --git a/lightningd/channel.c b/lightningd/channel.c index 0d8fa436b6b2..7f5c0d6d6381 100644 --- a/lightningd/channel.c +++ b/lightningd/channel.c @@ -399,13 +399,15 @@ void channel_set_state(struct channel *channel, wallet_channel_save(channel->peer->ld->wallet, channel); /* plugin notification channel_state_changed */ - derive_channel_id(&cid, &channel->funding_txid, channel->funding_outnum); - notify_channel_state_changed(channel->peer->ld, - &channel->peer->id, - &cid, - channel->scid, - old_state, - state); + if (state != old_state) { /* see issue #4029 */ + derive_channel_id(&cid, &channel->funding_txid, channel->funding_outnum); + notify_channel_state_changed(channel->peer->ld, + &channel->peer->id, + &cid, + channel->scid, + old_state, + state); + } } void channel_fail_permanent(struct channel *channel, const char *fmt, ...) diff --git a/tests/test_plugin.py b/tests/test_plugin.py index 8d647e9654e2..f12e67b3c186 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -731,14 +731,6 @@ def test_channel_state_changed_unilateral(node_factory, bitcoind): bitcoind.generate_block(100) # so it gets settled - msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") - event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) - assert(event['peer_id'] == peer_id) - assert(event['channel_id'] == cid) - assert(event['short_channel_id'] == scid) - assert(event['old_state'] == "AWAITING_UNILATERAL") # this actually happens - assert(event['new_state'] == "AWAITING_UNILATERAL") # note: same states - msg = l2.daemon.wait_for_log("channel_state_changed.*new_state.*") event = ast.literal_eval(re.findall(".*({.*}).*", msg)[0]) assert(event['peer_id'] == peer_id)