Anchor outputs break many assumptions in our tests:
1. Remove some hardcoded numbers in favor of a fee calc, so we only have to
change in one place.
FIXME: This should also be done for elements!
2. Do binary search to get feerate for a given closing fee.
3. Don't assume output #0: anchor outputs perturb them.
4. Don't assume we can make 1ksat channels (anchors cost 660 sats!).
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
It might have already happened, and anyway, we wait for the actual state
below.
```
# make database snapshot of l2
l2.stop()
l2_db_path = os.path.join(l2.daemon.lightning_dir, chainparams['name'], 'lightningd.sqlite3')
l2_db_path_bak = os.path.join(l2.daemon.lightning_dir, chainparams['name'], 'lightningd.sqlite3.bak')
copyfile(l2_db_path, l2_db_path_bak)
l2.start()
sync_blockheight(bitcoind, [l2])
# push some money from l3->l2, so that the commit counter advances
l2.rpc.connect(l3.info['id'], 'localhost', l3.port)
> l2.daemon.wait_for_log('now ACTIVE')
tests/test_closing.py:908:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
contrib/pyln-testing/pyln/testing/utils.py:288: in wait_for_log
return self.wait_for_logs([regex], timeout)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <pyln.testing.utils.LightningD object at 0x7f0c145a32d0>
regexs = ['now ACTIVE'], timeout = 60
def wait_for_logs(self, regexs, timeout=TIMEOUT):
"""Look for `regexs` in the logs.
We tail the stdout of the process and look for each regex in `regexs`,
starting from last of the previous waited-for log entries (if any). We
fail if the timeout is exceeded or if the underlying process
exits before all the `regexs` were found.
If timeout is None, no time-out is applied.
"""
logging.debug("Waiting for {} in the logs".format(regexs))
exs = [re.compile(r) for r in regexs]
start_time = time.time()
pos = self.logsearch_start
while True:
if timeout is not None and time.time() > start_time + timeout:
print("Time-out: can't find {} in logs".format(exs))
for r in exs:
if self.is_in_log(r):
print("({} was previously in logs!)".format(r))
> raise TimeoutError('Unable to find "{}" in logs.'.format(exs))
E TimeoutError: Unable to find "[re.compile('now ACTIVE')]" in logs.
contrib/pyln-testing/pyln/testing/utils.py:264: TimeoutError
```
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
And when it's set, and we're SLOW_MACHINE, simply disable valgrind.
Since Travis (SLOW_MACHINE=1) only does VALGRIND=1 DEVELOPER=1 tests,
and VALGRIND=0 DEVELOPER=0 tests, it was missing tests which needed
DEVELOPER and !VALGRIND.
Instead, this demotes them to non-valgrind tests for SLOW_MACHINEs.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
I started replacing all get_node() calls, but got bored, so then just did the
tests which call get_node() 3 times or more.
Ends up not making a measurable speed difference, but it does make some
things neater and more standard.
Times with SLOW_MACHINE=1 (given that's how Travis tests):
Time before (non-valgrind):
393 sec (had 3 failures?)
Time after (non-valgrind):
410 sec
Time before (valgrind):
890 seconds (had 2 failures)
Time after (valgrind):
892 sec
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
It looked like we weren't printing the address on closing outputs.
But we are, because the 'scriptPubkey' field is in the 'outputs' db
table since 0.7.3 (66a47d2761).
So make the logic clearer, and remove a completely bogus comment (UTXOs
with closing_info are definitely spendable!).
We export the json_add_utxos() for future use, too.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
If the daemon already knows about the channel before it was stopped,
it won't get this message from gossipd. That's OK, since we explicitly
test for the channel being active two lines down.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
It's possible for our peer to publish a commitment tx that has already
updated our balance for an htlc before we've completed removing it from
our commitment tx (aka before we've updated our balance). This used to
crash, now we just update our balance (and the channel balance logs!)
and keep going.
If they've removed anything from our balance, we'll end up counting it
as chain_fees below. Not ideal but fine... probably.
On node start we replay onchaind's transactions from the database/from
our loaded htlc table. To keep things tidy, we shouldn't notify the
ledger about these, so we wrap pretty much everything in a flag that
tells us whether or not this is a replay.
There's a very small corner case where dust transactions will get missed
if the node crashes after the htlc has been added to the database but
before we've successfully notified onchaind about it.
Notably, most of the obtrusive updates to onchaind wrappings are due to
the fact that we record dust (ignored outputs) before we receive
confirmation of its confirmation.
Mostly we update existing tests to account for channel balances. In a
few places, new tests were needed as there wasn't an existing pathway
that tested the chain-fees for a few penalty cases
For cheats, we do a little bit of weird accounting. First we 'update'
our on-ledger balance to be the entirety of the channel's balance. Then,
as outputs get resolved, we record the fees and outputs as withdrawals
from this amount.
It's possible that they might successfully 'cheat', in which case we
record those as 'penalty' but debits (not credits).
We didn't wait until l2 processed the final state of HTLC #2, so
it might not include it when it drops onchain, leading to us only
getting 3 (not 4) sendrawtx calls.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Previously we've used the term 'funder' to refer to the peer
paying the fees for a transaction; v2 of openchannel will make
this no longer true. Instead we rename this to 'opener', or the
peer sending the 'open_channel' message, since this will be universally
true in a dual-funding world.
They were looking for specific amounts which proved to be rather flaky. Now
they look for specific outputs being available in the `listfunds` result after
everything was settled.
A CONSERVATIVE/3 target for them.
Some noisy changes to the tests as we had to update the estimatesmartfee
mock.
Changelog-Changed: We now use a higher feerate for resolving onchain HTLCs and for penalty transactions
We kept track of an URGENT, a NORMAL, and a SLOW feerate. They were used
for opening (NORMAL), mutual (NORMAL), UNILATERAL (URGENT) transactions
as well as minimum and maximum estimations, and onchain resolution.
We now keep track of more fine-grained feerates:
- `opening` used for funding and also misc transactions
- `mutual_close` used for the mutual close transaction
- `unilateral_close` used for unilateral close (commitment transactions)
- `delayed_to_us` used for resolving our output from our unilateral close
- `htlc_resolution` used for resolving onchain HTLCs
- `penalty` used for resolving revoked transactions
We don't modify our requests to our Bitcoin backend, as the next commit
will batch them !
Changelog-deprecated: The "urgent", "slow", and "normal" field of the `feerates` command are now deprecated.
Changelog-added: The fields "opening", "mutual_close", "unilateral_close", "delayed_to_us", "htlc_resolution" and "penalty" have been added to the `feerates` command.
Before this patch we would only update `channel->last_tx` with the newly
proposed closure tx from the peer if the fee of the new one was lower.
In negotiations where we are at the higher end and the peer starts
lower, all peer's subsequent proposals will be higher than his initial
proposal and in this case we would never update `channel->last_tx`
and would wrongly broadcast his initial proposal at the end of the
negotiation.
Fixes https://github.com/ElementsProject/lightning/issues/3549
Changelog-Fixed: Always broadcast the latest close transaction at the end of the close fee negotiation, instead of sometimes broadcasting the peer's initial closing proposal.
We still close the channel if we *send* an error, but we seem to have hit
another case where LND sends an error which seems transient, so this will
make a best-effort attempt to preserve our channel in that case.
Some test have to be modified, since they don't terminate as they did
previously :(
Changelog-Changed: quirks: We'll now reconnect and retry if we get an error on an established channel. This works around lnd sending error messages that may be non-fatal.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Spaces just make life a little harder for everyone.
(Plus, fix documentation: it's 'jsonrpc' not 'json' subsystem).
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
A log can have a default node_id, which can be overridden on a per-entry
basis. This changes the format of logging, so some tests need rework.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We were checking against hardcoded hrp and prefixes. Now we parametrize via
the chainparams.
Signed-off-by: Christian Decker <decker.christian@gmail.com>
This was weird right from the start, so we just split the table into integers
and blobs, so each column has a well-defined format. It is also required for
postgres not to cry about explicit casts in the `paramTypes` array.
Signed-off-by: Christian Decker <decker.christian@gmail.com>
It's generally clearer to have simple hardcoded numbers with an
#if DEVELOPER around it, than apparent variables which aren't, really.
Interestingly, our pruning test was always kinda broken: we have to pass
two cycles, since l2 will refresh the channel once to avoid pruning.
Do the more obvious thing, and cut the network in half and check that
l1 and l3 time out.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
VALGRIND=1, SLOW_MACHINE=0:
Before: 197.74 seconds
After: 135.43 seconds
Note that we now spend about 13 seconds in teardown, could probably
be optimized.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
If l2 doesn't think we're onchain yet, it treats the new connection from l1
as a reconnection, triggering 'ValueError: 1 nodes had unexpected reconnections'
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We're about to change the API, so this makes the tests still work
across the transition (and, as a bonus, tests our backwards compat
shim).
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
And clean up some dev ones which actually happen (mainly by calling
channel_fail_permanent which logs UNUSUAL, rather than
channel_internal_error which logs BROKEN).
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Because the call (wallet_extract_owned outputs) that prints that line can happen
_before_ or _after_ confirmation in block, adding `CONFIRMED` in the later.
make it a bit easier to track mutual channel closures by
adding broadcast txid to the listpeers billboard.
since lightningd manages the 'identity' of the closing tx we need
to send it back to closingd so it can update the billboard
appropriately.
In particular this matches the case of `their_unilateral/to_us` outputs, which
were missing their addresses so far.
Signed-off-by: Christian Decker <decker.christian@gmail.com>
We want to disallow using unconfirmed outputs by default, so making the
default 1 confirmation seems a good idea. This also matches `bitcoind`s
minimum confirmation requirement.
Arming however breaks some of our tests, so I used `minconf=0` for the
breaking tests and added a new test specifically for the `minconf` parameter
for `fundchannel`.
Signed-off-by: Christian Decker <decker.christian@gmail.com>
This is based on Christian's change, but removes all trace of the old codes.
I've proposed another spec change which removes this code altogether:
https://github.com/lightningnetwork/lightning-rfc/pull/544
Signed-off-by: Christian Decker <decker.christian@gmail.com>
Reported-by: Rusty Russell <@rustyrussell>
We no longer use `dev-override-fees` to set the fees, rather we
instrument the `bitcoind` proxy to return the desired feerates.
Signed-off-by: Christian Decker <@cdecker>
In one case we can reduce, in the others we eliminated if VALGRIND.
Here are the ten slowest tests on my laptop:
469.75s call tests/test_closing.py::test_closing_torture
243.61s call tests/test_closing.py::test_onchain_multihtlc_our_unilateral
222.73s call tests/test_closing.py::test_onchain_multihtlc_their_unilateral
217.80s call tests/test_closing.py::test_closing_different_fees
146.14s call tests/test_connection.py::test_dataloss_protection
138.93s call tests/test_connection.py::test_restart_many_payments
129.66s call tests/test_gossip.py::test_gossip_persistence
128.73s call tests/test_connection.py::test_no_fee_estimate
122.46s call tests/test_misc.py::test_htlc_send_timeout
118.79s call tests/test_closing.py::test_onchain_dust_out
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
generate was deprecated some time ago, so we added the generate_block()
helper. But many calls crept back in, and git master refuses it.
(test_blockchaintrack relied on the return value, so make generate_block
return the list of blocks).
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
After Ubuntu 18.10 upgrade, lots of new flake8 warnings.
$ flake8 --version:
3.5.0 (mccabe: 0.6.1, pycodestyle: 2.4.0, pyflakes: 1.6.0) CPython 3.6.7rc1 on Linux
Note it seems that W503 warned about line breaks before binary
operators, and W504 complains about them after. I prefer W504, so
disable W503.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
When we have multiple HTLCs with the same preimage and the same CLTV,
it doesn't matter what order we treat them (they're literally
identical). But when we offer HTLCs with the same preimage but
different CLTVs, the commitment tx outputs look identical, but the
HTLC txs are different: if we simply take the first HTLC which matches
(and that's not the right one), the HTLC signature we got from them
won't match. As we rely on the signature matching to detect the fee
paid, we get:
onchaind: STATUS_FAIL_INTERNAL_ERROR: grind_fee failed
So we alter match_htlc_output() to return an array of all matching
HTLC indices, which can have more than one entry for offered HTLCs.
If it's our commitment, we loop through until one of the HTLC
signatures matches. If it's their commitment, we choose the HTLC with
the largest CLTV: we're going to ignore it once that hits anyway, so
this is the most conservative approach. If it's a penalty, it doesn't
matter since we steal all HTLC outputs the same independent of CLTV.
For accepted HTLCs, the CLTV value is encoded in the witness script,
so this confusion isn't possible. We nonetheless assert that the
CLTVs all match in that case.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We set up HTLCs with the same preimage and both different and same
CLTVs in both directions, then make sure that onchaind is OK and that
the HTLCs are failed without causing downstream failure.
We do this for both our-unilateral and their-unilateral cases.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Create a second HTLC with a different CTLV but same preimage; onchaind
uses the wrong signature and fails to grind it.
Reported-by: molz (#c-lightning)
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
My test case is a mainnet gossip store with 22107 channels, and
time to do `lightning-cli listchannels`:
Before: `lightning-cli listchannels` DEVELOPER=0
real 0m1.303000-1.324000(1.3114+/-0.0091)s
After:
real 0m0.629000-0.695000(0.64985+/-0.019)s
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We extract the tx from the logs, and then we wait until that hits
the mempool. This is more reliable than 'sendrawtx' in the logs,
which might catch a previous sendrawtx; it's also more explicit
that we expect that tx exactly.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Manipulate fees via fake-bitcoin-cli. It's not quite the same, as
these are pre-smoothing, so we need a restart to override that where
we really need an exact change. Or we can wait until it reaches a
certain value in cases we don't care about exact amounts.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We don't respond to fee changes until we're locked in: make sure we catch
up at that point.
Note that we use NORMAL fees during opening, but IMMEDIATE after, so
this often sends a fee update. The tests which break, we set those
feerates to be equal.
This (sometimes) changes the behavior of test_permfail, as we now
get an immediate commit, so that is fixed too so we always wait for
that to complete.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
This is a noop if we're opening a new channel (channel_fees_can_change(channel)
is false until funding locked in), but important if we're restarting.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We don't update a channel's feerate on reestablishment: we insert a restart
in test_onchain_different_fees() (which we'll need soon anyway) to show it.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We got an index error, because status had only one field (onchaind not
started yet).
> wait_for(lambda: only_one(p.rpc.listpeers(l1.info['id'])['peers'][0]['channels'])['status'][1] == 'ONCHAIN:Tracking mutual close transaction')
E IndexError: list index out of range1
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Normal wallet txs get reconfirmed as blocks come in, but ones which need
closeinfo are more fragile, so we do it manually using txwatch for them.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We now simply maintain a pubkey set for connected peers (we only care
if there's a reconnect), not the entire peer structure.
lightningd no longer queries us for getpeers: it knows more than we do
already.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
There's now a potential race: the source peer connect returns, but in
destination peer the master hasn't read the connect message from
connectd, so the peer isn't in listpeers yet.
(Previously the connection stayed in connectd, so there was no such
window).
This is an occasional issue in a few places.
Note that we take the opportunity to speed up test_disconnectpeer too
while we're there.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Prior to this, lightningd would hand uninteresting peers back to connectd,
which would then return it to lightningd if it sent a non-gossip msg,
or if lightningd asked it to release the peer.
Now connectd hands the peer to lightningd once we've done the init
handshake, which hands it off to openingd.
This is a deep structural change, so we do the minimum here and cleanup
in the following patches.
Lightningd:
1. Remove peer_nongossip handling from connect_control and peer_control.
2. Remove list of outstanding fundchannel command; it was only needed to
find the race between us asking connectd to release the peer and it
reconnecting.
3. We can no longer tell if the remote end has started trying to fund a
channel (until it has succeeded): it's very transitory anyway so not
worth fixing.
4. We now always have a struct peer, and allocate an uncommitted_channel
for it, though it may never be used if neither end funds a channel.
5. We start funding on messages for openingd: we can get a funder_reply
or a fundee, or an error in response to our request to fund a channel.
so we handle all of them.
6. A new peer_start_openingd() is called after connectd hands us a peer.
7. json_fund_channel just looks through local peers; there are none
hidden in connectd any more.
8. We sometimes start a new openingd just to send an error message.
Openingd:
1. We always have information we need to accept them funding a channel (in
the init message).
2. We have to listen for three fds: peer, gossip and master, so we opencode
the poll.
3. We have an explicit message to start trying to fund a channel.
4. We can be told to send a message in our init message.
Testing:
1. We don't handle some things gracefully yet, so two tests are disabled.
2. 'hand_back_peer .*: now local again' from connectd is no longer a message,
openingd says 'Handed peer, entering loop' once its managing it.
3. peer['state'] used to be set to 'GOSSIPING' (otherwise this field doesn't
exist; 'state' is now per-channel. It doesn't exist at all now.
4. Some tests now need to turn on IO logging in openingd, not connectd.
5. There's a gap between connecting on one node and having connectd on
the peer hand over the connection to openingd. Our tests sometimes
checked getpeers() on the peer, and didn't see anything, so line_graph
needed updating.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
72d103d6bb deprecated DEVELOPER env var
in favor of config.vars, but didn't update test_closing.py or test_gossip.py.
5d0a54b7f0 then removed the explicit
DEVELOPER= setting from Travis.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
It simply wasn't waiting for us to register the peer before attempting to open a
connection. Moved into a separate test to be able rerun multiple times.
Signed-off-by: Christian Decker <decker.christian@gmail.com>
