Notification support

[rustyrussell]

This is my attempt to answer #3925. Commands should be able to feed notifications back concerning command progress; to do so, we use notifications (JSON requests without an id). Plugins can feed them back to the correct sender by putting id in the params.

1. It has a problem in that we cannot introduce it immediately, since clients may not expect it, hence allow-deprecated-apis test.
2. It's not clear what the libplugin and pyln APIs for these should be. They currently ignore it.
3. I only implemented "message": for now, but others are possible (eg. some progress counter).

Obviously, this needs discussion and documentation, but this shows what an implementation might look like.

@shesek might have particular opinions on this kind of API!

[cdecker]

I really like the idea of using notifications in order to update the caller on what's going on. From what I can see this is notifying using the notify topic, and then disambiguates using the id field in the params and matches that with the command that caused the notification, correct?

My only concern is that it might break clients that do not expect notifications to be interleaved with the response they are waiting for, and there is no way to opt into receiving the notifications as it stands right now. There is absolutely no requirement for the notified party to have subscribed before receiving notificactions in the JSON-RPC 2.0 spec, but it'd be better I think. The problem is how to do that, and all mechanisms I can come up with either

• require associating out-of-cmd subscriptions with the cmd (prepending a subscribe RPC call to the actual command, incurring in the subscription storage before we can associate it with the cmd, and incurs an extra roundtrip)
• may be lossy (subscribing after issuing the real command may drop some notifications produced inbetween)

The only way I can think of making this easy is by adding fields to the JSON-RPC object itself, along with id, method and params, but I'm pretty sure that'd not be supported by some JSON-RPC frameworks. Since they'd initiate the entire thing, it'd at least not break them outright.

Long story short: I like the idea, and implementation, would want a better opt-in mechanism, but can't come up with one myself... 😉

[rustyrussell]

Agreed. We could have a enable-notifications JSON command which turns them on, which would be perfectly backwards compat though (it would not generally be done on a per-command basis, though you could toggle it if you really wanted to).

This may combine well with using logging levels: I think this makes sense in general as we get more sophisticated. For example, I can see myself wanting pay with debug-level notifications if stuff is failing. Rather than having the client have to filter these, the enable-notifications could take a level arg.

Will rework along these lines?

[rustyrussell]

OK, this is the Final Form (rebased on top of #4086 ).

The only remaining question is nomenclature: should we refer to these as "updates" instead of "notifications"?

[ZmnSCPxj]

concept ack especially now that it is opt-in, I have the same concern as @cdecker regarding existing clients not expecting notifications they have not subscribed to on the RPC interface.

[rustyrussell]

Trivial rebase.

[cdecker]

Rebased on top of master and added a tiny fixup that addresses a failing make check-manpages test in CI.

Still has a valgrind issue with run-human-mode that I could not quite track down in-between other tasks :-)

VALGRIND=1 valgrind -q --error-exitcode=7 --track-origins=yes --leak-check=full --show-reachable=yes --errors-for-leak-kinds=all cli/test/run-human-mode > /dev/null
run-human-mode: WARNING: default network changing in 2020: please set network=testnet in config!
==13330== Conditional jump or move depends on uninitialised value(s)
==13330==    at 0x150027: strends (str.h:45)
==13330==    by 0x150027: enable_notifications (lightning-cli.c:578)
==13330==    by 0x150027: test_main (lightning-cli.c:707)
==13330==    by 0x10C133: main (run-human-mode.c:176)
==13330==  Uninitialised value was created by a stack allocation
==13330==    at 0x14F5BD: test_main (lightning-cli.c:604)
==13330== 
==13330== Conditional jump or move depends on uninitialised value(s)
==13330==    at 0x15004E: strends (str.h:45)
==13330==    by 0x15004E: enable_notifications (lightning-cli.c:578)
==13330==    by 0x15004E: test_main (lightning-cli.c:707)
==13330==    by 0x10C133: main (run-human-mode.c:176)
==13330==  Uninitialised value was created by a stack allocation
==13330==    at 0x14F5BD: test_main (lightning-cli.c:604)
==13330== 
==13330== Use of uninitialised value of size 8
==13330==    at 0x150061: strends (str.h:48)
==13330==    by 0x150061: enable_notifications (lightning-cli.c:578)
==13330==    by 0x150061: test_main (lightning-cli.c:707)
==13330==    by 0x10C133: main (run-human-mode.c:176)
==13330==  Uninitialised value was created by a stack allocation
==13330==    at 0x14F5BD: test_main (lightning-cli.c:604)
==13330== 
==13330== Conditional jump or move depends on uninitialised value(s)
==13330==    at 0x4C366E6: memmove (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==13330==    by 0x1500BD: memcpy (string_fortified.h:34)
==13330==    by 0x1500BD: test_read (run-human-mode.c:163)
==13330==    by 0x1500BD: enable_notifications (lightning-cli.c:580)
==13330==    by 0x1500BD: test_main (lightning-cli.c:707)
==13330==    by 0x10C133: main (run-human-mode.c:176)
==13330==  Uninitialised value was created by a stack allocation
==13330==    at 0x14F5BD: test_main (lightning-cli.c:604)
==13330== 
==13330== Use of uninitialised value of size 8
==13330==    at 0x4C32CF2: strlen (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==13330==    by 0x1500A1: test_read (run-human-mode.c:160)
==13330==    by 0x1500A1: enable_notifications (lightning-cli.c:580)
==13330==    by 0x1500A1: test_main (lightning-cli.c:707)
==13330==    by 0x10C133: main (run-human-mode.c:176)
==13330==  Uninitialised value was created by a stack allocation
==13330==    at 0x14F5BD: test_main (lightning-cli.c:604)
==13330== 
==13330== Use of uninitialised value of size 8
==13330==    at 0x4C32D04: strlen (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==13330==    by 0x1500A1: test_read (run-human-mode.c:160)
==13330==    by 0x1500A1: enable_notifications (lightning-cli.c:580)
==13330==    by 0x1500A1: test_main (lightning-cli.c:707)
==13330==    by 0x10C133: main (run-human-mode.c:176)
==13330==  Uninitialised value was created by a stack allocation
==13330==    at 0x14F5BD: test_main (lightning-cli.c:604)
==13330== 
==13330== 
==13330== More than 10000000 total errors detected.  I'm not reporting any more.
==13330== Final error counts will be inaccurate.  Go fix your program!
==13330== Rerun with --error-limit=no to disable this cutoff.  Note
==13330== that errors may occur in your program without prior warning from
==13330== Valgrind, because errors are no longer being displayed.
==13330== 

I'd love to see this merged soon @rustyrussell :-)

[rustyrussell]

Yeah, those tests just delivered a canned reponse; in this case, it filled the buffer.

Fixed them to disable notifications.

[rustyrussell]

Trivial rebase to fix conflict, valgrind fixes, and folded cdecker fix.