Originally I (incorrectly?) assumed that since TX_COMMITMENT_SIGNED
always came before TX_SIGNATURES, we would always receive a response
from openchannel_update (w/ commitment_secured = true) before getting
notification of receipt of the peer's signatures.
But it's observable in the logs of hung tests that this in fact is a
wrong assumption -- the notification for the tx_sigs arrives at our
spender plugin before the callback from our openchannel_update RPC.
This mis-ordering causes a hang.
Luckily we're pretty much setup to handle this race already w/ states
etc, minus actually calling the method advance the plot in case we're
ready.
2022-07-26T05:37:59.4529095Z lightningd-1 2022-07-26T05:10:07.395Z DEBUG 035d2b1192dfba134e10e540875d366ebc8bc353d5aa766b80c090b39c3a5d885d-dualopend-chan#2: peer_in WIRE_COMMITMENT_SIGNED
2022-07-26T05:37:59.4530452Z lightningd-1 2022-07-26T05:10:07.396Z DEBUG 035d2b1192dfba134e10e540875d366ebc8bc353d5aa766b80c090b39c3a5d885d-hsmd: Got WIRE_HSMD_VALIDATE_COMMITMENT_TX
2022-07-26T05:37:59.4530719Z lightningd-1 2022-07-26T05:10:07.396Z DEBUG hsmd: Client: Received message 35 from client
2022-07-26T05:37:59.4531386Z lightningd-1 2022-07-26T05:10:07.396Z DEBUG 035d2b1192dfba134e10e540875d366ebc8bc353d5aa766b80c090b39c3a5d885d-dualopend-chan#2: billboard: channel open: commitment received, sending to lightningd to save
2022-07-26T05:37:59.4531856Z lightningd-1 2022-07-26T05:10:07.398Z DEBUG 035d2b1192dfba134e10e540875d366ebc8bc353d5aa766b80c090b39c3a5d885d-dualopend-chan#2: peer_in WIRE_TX_SIGNATURES
>>> 2022-07-26T05:37:59.4532553Z lightningd-1 2022-07-26T05:10:07.400Z DEBUG plugin-spenderp: mfc 60:`openchannel_peer_sigs` notice received for channel 9d145e763f08ee6f715ba7677f869cbb9580c7406f4d0b0ff3a0987efe501e13 <<<< THIS ONE WAS ASSUMED TO COME AFTER openchannel_update (next line)
2022-07-26T05:37:59.4533048Z lightningd-1 2022-07-26T05:10:07.400Z DEBUG plugin-spenderp: mfc 60, dest 0: openchannel_update 035d2b1192dfba134e10e540875d366ebc8bc353d5aa766b80c090b39c3a5d885d returned.
2022-07-26T05:37:59.4554292Z lightningd-1 2022-07-26T05:10:07.400Z DEBUG plugin-spenderp: mfc 60: parallel `openchannel_update`.
2022-07-26T05:37:59.4555485Z lightningd-1 2022-07-26T05:10:07.400Z DEBUG plugin-spenderp: mfc 60: funding tx 50425e20dbf0ca6fe112a8811b8048edb5bfa8d2922079668c5f353b859b45cb
2022-07-26T05:37:59.4557934Z lightningd-1 2022-07-26T05:10:07.508Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-hsmd: Got WIRE_HSMD_CUPDATE_SIG_REQ
2022-07-26T05:37:59.4558244Z lightningd-1 2022-07-26T05:10:07.508Z DEBUG hsmd: Client: Received message 3 from client
2022-07-26T05:37:59.4558738Z lightningd-3 2022-07-26T05:11:03.234Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-gossipd: seeker: startup peer finished
2022-07-26T05:37:59.4559209Z lightningd-3 2022-07-26T05:11:03.234Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-gossipd: seeker: state = PROBING_SCIDS Seeking scids 1 - 105
(The last 2 log messages (from a different node) are >1min after the last
log line from lightning-1, because lightning-1 hung)
Hacked lightningd up to test this (such that notification always sent
before the RPC response, works as intended w/ patch)
Mostly comments and docs: some places are actually paths, which
I have avoided changing. We may migrate them slowly, particularly
when they're user-visible.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Things allocated by libwally all get the tal_name "wally_tal",
which cost me a few hours trying to find a leak.
In the case where we're making one of the allocations the parent
of the others (e.g. a wally_psbt), we can do better: supply a name
for the tal_wally_end().
So I add a new tal_wally_end_onto() which does the standard
tal_steal() trick, and also changes the (typechecked!) name.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We always allocate a new `struct command` when we get a full JSON
object from stdin:
b2df01dc73/plugins/libplugin.c (L1229-L1233)
If it happens to be a notification, we pass the `struct command` to
the handler, and not free it ourselves:
b2df01dc73/plugins/libplugin.c (L1270-L1275)
There are only nine points in `plugins/libplugin.c` where we `tal_free`
anything, and only one of them frees a `struct command`:
b2df01dc73/plugins/libplugin.c (L224-L234)
The above function `command_complete` is not appropriate for
notification handlers; the above function sends out a response
to our stdout, which a notification handler should not do.
However, as-is, it does mean that notification handling leaks
`struct command` objects, which can be problematic if we ever
have future built-in plugins which are significantly more
dependent on notifications.
This commit changes notification handlers to return
`struct command_result *`, because possibly in the future
notification handlers may want to perform `send_outreq`, so we
might as well use our standard convention for callbacks, and
to encourage future developers to check how to properly
terminate notification handlers (and free up the
`struct command`).
We also now provide a `notification_handled` function which a
notification handler must eventually call, as well as a
`notification_handler_pending` which is just a snowclone of
`command_still_pending`.
Before:
Ten builds, laptop -j5, no ccache:
```
real 0m36.686000-38.956000(38.608+/-0.65)s
user 2m32.864000-42.253000(40.7545+/-2.7)s
sys 0m16.618000-18.316000(17.8531+/-0.48)s
```
Ten builds, laptop -j5, ccache (warm):
```
real 0m8.212000-8.577000(8.39989+/-0.13)s
user 0m12.731000-13.212000(12.9751+/-0.17)s
sys 0m3.697000-3.902000(3.83722+/-0.064)s
```
After:
Ten builds, laptop -j5, no ccache: 8% faster
```
real 0m33.802000-35.773000(35.468+/-0.54)s
user 2m19.073000-27.754000(26.2542+/-2.3)s
sys 0m15.784000-17.173000(16.7165+/-0.37)s
```
Ten builds, laptop -j5, ccache (warm): 1% faster
```
real 0m8.200000-8.485000(8.30138+/-0.097)s
user 0m12.485000-13.100000(12.7344+/-0.19)s
sys 0m3.702000-3.889000(3.78787+/-0.056)s
```
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
They get grafted into clone, so have them parented there. Otherwise
we get a small leak every time we RBF.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We need to know what the lease we're expecting is. To do this
we pass around the hex encoded portion of the wire format.
We can use this passed in expected lease rates to confirm that the peer
is, in fact, using the same rates as what we have currently.
Changelog-Added: JSON-RPC: fundchannel, multifundchannel, and openchannel_init now accept a 'compact_lease' for any requested funds
If we only add a single input/output for the funding transaction,
we'll only call openchannel_update once, which results in
a crash because the dest->state will never advance to
MULTIFUNDCHANNEL_UPDATED;
Instead, we update to UPDATED before we check for doneness.
It's unlikely but possible that a race condition will result in us not
being at the 'secured' state yet here.
Crashlogs. All required msgs are received (in order)
from peers, but the crash suggests they weren't relayed/processed by the
spender plugin in the order received.
WIRE_TX_SIGNATURES is passed the the plugin via a notification;
WIRE_COMMITMENT_SIGNED is returned as the result of an RPC call.
```
021-03-25T12:12:33.5213247Z lightningd-1: 2021-03-25T11:50:13.351Z DEBUG 035d2b1192dfba134e10e540875d366ebc8bc353d5aa766b80c090b39c3a5d885d-dualopend-chan#3: peer_in WIRE_COMMITMENT_SIGNED
2021-03-25T12:12:33.5221140Z lightningd-1: 2021-03-25T11:50:13.659Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-dualopend-chan#1: peer_in WIRE_COMMITMENT_SIGNED
2021-03-25T12:12:33.5228462Z lightningd-1: 2021-03-25T11:50:14.169Z DEBUG 035d2b1192dfba134e10e540875d366ebc8bc353d5aa766b80c090b39c3a5d885d-dualopend-chan#3: peer_in WIRE_TX_SIGNATURES
2021-03-25T12:12:33.5230957Z lightningd-1: 2021-03-25T11:50:14.375Z DEBUG plugin-spenderp: mfc 275, dest 1: openchannel_update 035d2b1192dfba134e10e540875d366ebc8bc353d5aa766b80c090b39c3a5d885d returned.
2021-03-25T12:12:33.5233307Z lightningd-1: 2021-03-25T11:50:14.539Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-dualopend-chan#1: peer_in WIRE_TX_SIGNATURES
2021-03-25T12:12:33.5235120Z lightningd-1: 2021-03-25T11:50:17.240Z INFO plugin-spenderp: Killing plugin: exited during normal operation
2021-03-25T12:12:33.5236707Z lightningd-1: 2021-03-25T11:50:17.260Z **BROKEN** plugin-spenderp: Plugin marked as important, shutting down lightningd!
```
Fixes#4455
Previously this ported errors around as JSON. A nicer thing to do is to
deconstruct/reconstruct it; this also allows us to create our own errors
from within the multifundchannel family.
We should actually be including this (as it may define _GNU_SOURCE
etc) before any system headers. But where we include <assert.h> we
often didn't, because check-includes would complain that the headers
included it too.
Weaken that check, and include config.h in C files before assert.h.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
This makes for more useful errors. It prints where it was up to in
the guide, but doesn't print the entire JSON it's scanning.
Suggested-by: Christian Decker
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
This will cause blow ups for v2 multifundchannel attempts with failures,
but allows us to return the expected errors for single-shot
fundchannel attempts.
Error handling is coming, i promise
Ideally we'd 'cure' the error and re-attempt, except that if this was a
bitcoin-backend 'failure to broadcast' then it really needs user
intervention to figure out what's wrong -- it's possible that the
peer successfully broadcast the transaction
We only have output scripts for v1 protocols after the
fundchannel_start/openchannel_init round. We need to add them before
we get into the openchannel_update rounds, however, so we do that here.
niftynei
Rusty Russell
ZmnSCPxj jxPCSnmZ