By having gossipwith filter out messages we don't want, we can get the counts of
expected messages correct, and not hit errors like this:
```
def test_gossip_throttle(node_factory, bitcoind, chainparams):
"""Make some gossip, test it gets throttled"""
l1, l2, l3, l4 = node_factory.line_graph(4, wait_for_announce=True,
opts=[{}, {}, {}, {'dev-throttle-gossip': None}])
# We expect: self-advertizement (3 messages for l1 and l4) plus
# 4 node announcements, 3 channel announcements and 6 channel updates.
# We also expect it to send a timestamp filter message.
# (We won't take long enough to get a ping!)
expected = 4 + 4 + 3 + 6 + 1
# l1 is unlimited
start_fast = time.time()
out1 = subprocess.run(['devtools/gossipwith',
'--all-gossip',
'--hex',
'--network={}'.format(TEST_NETWORK),
'--max-messages={}'.format(expected),
'{}@localhost:{}'.format(l1.info['id'], l1.port)],
check=True,
timeout=TIMEOUT, stdout=subprocess.PIPE).stdout.split()
time_fast = time.time() - start_fast
assert time_fast < 2
# Remove timestamp filter, since timestamp will change!
out1 = [m for m in out1 if not m.startswith(b'0109')]
# l4 is throttled
start_slow = time.time()
out2 = subprocess.run(['devtools/gossipwith',
'--all-gossip',
'--hex',
'--network={}'.format(TEST_NETWORK),
'--max-messages={}'.format(expected),
'{}@localhost:{}'.format(l4.info['id'], l4.port)],
check=True,
timeout=TIMEOUT, stdout=subprocess.PIPE).stdout.split()
time_slow = time.time() - start_slow
assert time_slow > 3
# Remove timestamp filter, since timestamp will change!
out2 = [m for m in out2 if not m.startswith(b'0109')]
# Contents should be identical (once uniquified, since each
# doubles-up on its own gossip)
> assert set(out1) == set(out2)
E AssertionError: assert {b'010054b1907bdf639c9060e0fa4bca02419c46f75a99f0908b87a2e09711d5d031ba76b8fd07acc8be1b2fac9e31efb808e5d362c32ef4665...
E Extra items in the left set:
E b'01010ad5be8b9ba029245c2ae2d667af7ead7c0129c479c7fd7145a9b65931e90222082e6e4ab37ef60ebd10f1493d73e8bf7a40c4ae5f7d87cc...8488830b60f7e744ed9235eb0b1ba93283b315c035180266e44a554e494f524245414d2d333930353033622d6d6f64646564000000000000000000'
E Extra items in the right set:
E b'01079f87eb580b9e5f11dc211e9fb66abb3699999044f8fe146801162393364286c6000000010000006c010101'
```
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We can be a bit early in our assertion:
```
@unittest.skipIf(os.getenv('TEST_DB_PROVIDER', 'sqlite3') != 'sqlite3', "sqlite3-specific DB manip")
def test_reconnect_remote_sends_no_sigs(node_factory):
"""We re-announce, even when remote node doesn't send its announcement_signatures on reconnect.
"""
l1, l2 = node_factory.line_graph(2, wait_for_announce=True, opts={'may_reconnect': True,
'dev-no-reconnect': None})
# Wipe l2's gossip_store
l2.stop()
gs_path = os.path.join(l2.daemon.lightning_dir, TEST_NETWORK, 'gossip_store')
os.unlink(gs_path)
l2.start()
# l2 will now uses (REMOTE's) announcement_signatures it has stored
wait_for(lambda: l2.rpc.listchannels()['channels'] != [])
# Remove remote signatures from l1 so it asks for them (and delete gossip store)
l1.db_manip("UPDATE channels SET remote_ann_node_sig=NULL, remote_ann_bitcoin_sig=NULL")
gs_path = os.path.join(l1.daemon.lightning_dir, TEST_NETWORK, 'gossip_store')
os.unlink(gs_path)
l1.restart()
l1.connect(l2)
l1needle = l1.daemon.logsearch_start
l2needle = l2.daemon.logsearch_start
# l1 asks once, l2 replies once.
# Make sure we get all the msgs!
time.sleep(5)
l1.daemon.wait_for_log('peer_out WIRE_ANNOUNCEMENT_SIGNATURES')
l2.daemon.wait_for_log('peer_out WIRE_ANNOUNCEMENT_SIGNATURES')
l1msgs = [l.split()[4] for l in l1.daemon.logs[l1needle:] if 'WIRE_ANNOUNCEMENT_SIGNATURES' in l]
> assert l1msgs == ['peer_out', 'peer_in']
E AssertionError: assert ['peer_out'] == ['peer_out', 'peer_in']
E Right contains one more item: 'peer_in'
E Full diff:
E - ['peer_out', 'peer_in']
E + ['peer_out']
```
```
lightningd-2 2025-01-24T05:53:22.862Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-connectd: peer_out WIRE_ANNOUNCEMENT_SIGNATURES
lightningd-1 2025-01-24T05:53:22.864Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-channeld-chan#1: peer_in WIRE_ANNOUNCEMENT_SIGNATURES
lightningd-1 2025-01-24T05:53:22.885Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-chan#1: channel_gossip: received announcement sigs for 103x1x0 (we have 103x1x0)
{'github_repository': 'ElementsProject/lightning', 'github_sha': 'e9d36f2b8ecd45882753cbe062c355e40bc7109c', 'github_ref': 'refs/pull/8027/merge', 'github_ref_name': 'HEAD', 'github_run_id': 12943530601, 'github_head_ref':
```
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Sometimes they connect too fast, so we don't get a chance to ratelimit all of them:
```
def test_connect_ratelimit(node_factory, bitcoind):
"""l1 has 5 peers, restarts, make sure we limit"""
nodes = node_factory.get_nodes(6,
opts=[{'dev-limit-connections-inflight': None, 'may_reconnect': True}] + [{'may_reconnect': True}] * 5)
l1 = nodes[0]
nodes = nodes[1:]
addr = l1.rpc.newaddr()['bech32']
for n in nodes:
bitcoind.rpc.sendtoaddress(addr, (FUNDAMOUNT + 1000000) / 10**8)
bitcoind.generate_block(1, wait_for_mempool=len(nodes))
sync_blockheight(bitcoind, [l1])
for n in nodes:
l1.rpc.connect(n.info['id'], 'localhost', n.port)
l1.rpc.fundchannel(n.info['id'], FUNDAMOUNT)
# Make sure all channels are established and announced.
bitcoind.generate_block(6, wait_for_mempool=len(nodes))
wait_for(lambda: len(l1.rpc.listchannels()['channels']) == len(nodes) * 2)
assert not l1.daemon.is_in_log('Unblocking for')
l1.restart()
# The first will be ok, but others should block and be unblocked.
> l1.daemon.wait_for_logs((['Unblocking for ']
+ ['Too many connections, waiting'])
* (len(nodes) - 1))
tests/test_connection.py:4721:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <pyln.testing.utils.LightningD object at 0x7f6e288a3a60>
regexs = ['Unblocking for ', 'Too many connections, waiting', 'Unblocking for ', 'Too many connections, waiting', 'Unblocking for ', 'Too many connections, waiting', ...]
timeout = 180
def wait_for_logs(self, regexs, timeout=TIMEOUT):
"""Look for `regexs` in the logs.
The logs contain tailed stdout of the process. We look for each regex
in `regexs`, starting from `logsearch_start` which normally is the
position of the last found entry of a previous wait-for logs call.
The ordering inside `regexs` doesn't matter.
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()
while True:
if self.logsearch_start >= len(self.logs):
if not self.logs_catchup():
time.sleep(0.25)
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('Unblocking for '), re.compile('Too many connections, waiting')]" in logs.
```
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
```
____________________ ERROR at teardown of test_xpay_maxfee _____________________
...
# Format a nice list of everything that went wrong and raise an exception
request.node.has_errors = True
> raise ValueError(str(errors))
E ValueError:
E Node errors:
E - lightningd-1: Node exited with return code 1
E Global errors:
```
And:
```
@unittest.skipIf(TEST_NETWORK != 'regtest', 'too dusty on elements')
def test_xpay_maxfee(node_factory, bitcoind, chainparams):
"""Test which shows that we don't excees maxfee"""
outfile = tempfile.NamedTemporaryFile(prefix='gossip-store-')
subprocess.check_output(['devtools/gossmap-compress',
'decompress',
'--node-map=3301=022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59',
'tests/data/gossip-store-2024-09-22.compressed',
outfile.name]).decode('utf-8').splitlines()
AMOUNT = 100_000_000
# l2 will warn l1 about its invalid gossip: ignore.
# We throttle l1's gossip to avoid massive log spam.
> l1, l2 = node_factory.line_graph(2,
# This is in sats, so 1000x amount we send.
fundamount=AMOUNT,
opts=[{'gossip_store_file': outfile.name,
'subdaemon': 'channeld:../tests/plugins/channeld_fakenet',
'allow_warning': True,
'dev-throttle-gossip': None},
{'allow_bad_gossip': True}])
tests/test_xpay.py:509:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
contrib/pyln-testing/pyln/testing/utils.py:1720: in line_graph
nodes = self.get_nodes(num_nodes, opts=opts)
contrib/pyln-testing/pyln/testing/utils.py:1602: in get_nodes
return [j.result() for j in jobs]
contrib/pyln-testing/pyln/testing/utils.py:1602: in <listcomp>
return [j.result() for j in jobs]
/opt/hostedtoolcache/Python/3.10.16/x64/lib/python3.10/concurrent/futures/_base.py:458: in result
return self.__get_result()
/opt/hostedtoolcache/Python/3.10.16/x64/lib/python3.10/concurrent/futures/_base.py:403: in __get_result
raise self._exception
/opt/hostedtoolcache/Python/3.10.16/x64/lib/python3.10/concurrent/futures/thread.py:58: in run
result = self.fn(*self.args, **self.kwargs)
contrib/pyln-testing/pyln/testing/utils.py:1653: in get_node
node.start(wait_for_bitcoind_sync)
contrib/pyln-testing/pyln/testing/utils.py:1015: in start
self.daemon.start(stderr_redir=stderr_redir)
contrib/pyln-testing/pyln/testing/utils.py:671: in start
self.wait_for_log("Server started with public key")
contrib/pyln-testing/pyln/testing/utils.py:355: in wait_for_log
return self.wait_for_logs([regex], timeout)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <pyln.testing.utils.LightningD object at 0x7f27ab586c20>
regexs = ['Server started with public key'], timeout = 180
def wait_for_logs(self, regexs, timeout=TIMEOUT):
"""Look for `regexs` in the logs.
The logs contain tailed stdout of the process. We look for each regex
in `regexs`, starting from `logsearch_start` which normally is the
position of the last found entry of a previous wait-for logs call.
The ordering inside `regexs` doesn't matter.
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()
while True:
if self.logsearch_start >= len(self.logs):
if not self.logs_catchup():
time.sleep(0.25)
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('Server started with public key')]" in logs.
```
gossipd (and other plugins) simply take too long to digest the gossmap under valgrind.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Pyln logger's configuration was unexpectedly being overwritten by the root logger during the autogenerated examples test, complicating error debugging.
We resolved this by introducing a pytest fixture to reapply the logger configuration before the tests executes.
Changelog-None.
Fixes: https://github.com/ElementsProject/lightning/issues/8023
The updated API requires typed htables to explicitly state whether they
allow duplicates: for most cases we don't, but we've had issues in the
past.
This is a big patch, but mainly mechanical.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Keep a proper cache of all possible ones. I think this may be the
timeout problem: according to the logs, channeld_fakenet stops responding
and thus HTLCs eventually time out.
```
```
2024-12-16T23:16:16.4874420Z lightningd-1 2024-12-16T22:45:14.068Z UNUSUAL 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-channeld-chan#1: Adding HTLC 18446744073709551615 too slow: killing connection
```
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We can get the reply_short_channel_ids_end in the messages when
we make a query:
```
2024-11-29T07:39:28.8550652Z time_fast = time.time() - start_fast
2024-11-29T07:39:28.8551067Z assert time_fast < 2
2024-11-29T07:39:28.8551487Z out3 = [m for m in out3 if not m.startswith(b'0109')]
2024-11-29T07:39:28.8552158Z > assert set(out1) == set(out3)
...
2024-11-29T07:39:28.8675516Z E Extra items in the right set:
2024-11-29T07:39:28.8675887Z E b'010606226e46111a0b59caaf126043eb5bbf28c34f3a5e332a1fc7b2b73cf188910f01'
```
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Cut & paste from the forwarding code, where we don't let onions use the
unannounced scids. Obviously local commands can use them.
Reported-by: @michael1011
Changelog-Fixed: JSON-RPC: xpay now works through unannounced channels.
Note that the slight code reorder changes the JSON order, which is generally
undefined, but our doc checker is very strict!
Changelog-Changed: `xpay` now gives the same JSON success return as documented by `pay` when `xpay-handle-pay` is set.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Fixes: https://github.com/ElementsProject/lightning/issues/7923
maxfeepercent is use by Zeus, so let's make that work.
maxfee is more precise, so it's the only xpay option (maxfee was added
to pay later).
[ Fix to ppm logic by Lagrang3, thanks! --RR ]
Fixes: https://github.com/ElementsProject/lightning/issues/7926
Changelog-Changed: JSON-RPC: With `xpay-handle-pay` set, xpay will now be used even if `pay` uses maxfeeprecent or exemptfee parameters (e.g. Zeus)
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
This means that it gets shown in listsendpays: omitting this broke spark, apparently!
Changelog-Changed: `xpay` now populates more fields, so `listsendpays` and `listpays` show `destination` and `amount_msat` fields for xpay payments.
Fixes: https://github.com/ElementsProject/lightning/issues/7881
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
If they give us the invstring, we can at least set who signed the invoice. Of course,
it might not be a real node_id (with blinded paths).
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
This appears in listsendpays / listpays, and is useful information (if we know!).
This doesn't fix old payments, but means that xpay can use this for new payments.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
It's actually tested by fetchinvoice, but doing an explicit test in Python
allows for schema checking!
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Changelog-Changed: JSON-RPC: `injectonionmessage` API simplified and documented.
See: https://github.com/ElementsProject/lightning/issues/7899
A node with 23 connections gets far too many debug messages.
Changelog-Fixed: `gossipd` now does logging at trace, not debug level.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We were handing "maxfee" to every getroutes call, even if we had already
used some of the fees.
Reported-by: @daywalker90
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Changelog-None: xpay is new this release.
In fact, there are several places where we try to decode old invoices,
and they should all work. The only place we should enforce expiration is
when we're going to pay.
This also revealed that xpay wasn't checking bolt11 expiries!
Reported-by: hMsats
Fixes: https://github.com/ElementsProject/lightning/issues/7869
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Changelog-Fixed: JSON-RPC: `decode` refused to decode expired bolt12 invoices.
- Run with environment variable `GENERATE_EXAMPLES`
- Update cln version in getinfo example on `make update-versions`
- Added two `dev` configs, dev-no-plugin-checksum and dev-no-version-checks, to match CI listconfigs
- Changed commando rpc example from `getinfo` to `newaddr` to avoid unneccessary file updates for future builds
- Stabilized `bkpr-editdescriptionbyoutpoint`, `listclosedchannels` and `listaddresses` examples
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Changelog-Changed: Protocol: we now create a low-priority (2016 down to 12 blocks fee target) anchor for low-fee unilateral closes even if there's no urgency.
The seeker can send a full gossip query, which means the ping doesn't happen
(it needs 14-45 seconds of quiet!).
We disable the gossip_queries feature, so it doesn't ask.
```
def test_ping_timeout(node_factory):
# Disconnects after this, but doesn't know it.
l1_disconnects = ['xWIRE_PING']
l1, l2 = node_factory.get_nodes(2, opts=[{'dev-no-reconnect': None,
'disconnect': l1_disconnects},
{'dev-no-ping-timer': None}])
l1.rpc.connect(l2.info['id'], 'localhost', l2.port)
# This can take 10 seconds (dev-fast-gossip means timer fires every 5 seconds)
l1.daemon.wait_for_log('seeker: startup peer finished', timeout=15)
# Ping timers runs at 15-45 seconds, *but* only fires if also 60 seconds
# after previous traffic.
> l1.daemon.wait_for_log('dev_disconnect: xWIRE_PING', timeout=60 + 45 + 5)
tests/test_connection.py:4194:
...
> raise TimeoutError('Unable to find "{}" in logs.'.format(exs))
E TimeoutError: Unable to find "[re.compile('dev_disconnect: xWIRE_PING')]" in logs.
```
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Rather than have lightningd call us repeatedly to try to connect, have
it tell us what peers are transient and aren't, and connectd will
automatically try to maintain that connection.
There's a new "downgrade_peer" message to tell it a peer is now
transient: to make it non-transient we simply tell connectd to
connect as a non-transient.
The first time, I missed that dual_open_control does its own state
transitions :(
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Changelog-Changed: `connectd` now handles maintaining/reconnecting to important peers, and we remember the last successful address we connected to.
Let lightningd feed us hints to try first, but we can extract the
addresses from node_announcement messages ourselves.
(Lightningd used to ask gossipd on our behalf: this is far simpler!)
One side effect of this is that we don't hand back address hints given to us
by lightningd: it would use these again for reconnecting. This is breaks
test_sendpay_grouping, so we disable it temporarily.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
If the first one doesn't use the entire timeout, the second might need longer
(I used TIMEOUT=10 normally):
```
FAILED tests/test_gossip.py::test_gossip_pruning - TimeoutError: Unable to find "[re.compile('Pruning channel 103x1x0 from network view')]" in logs.
```
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
