ChannelMonitor and related log entries can generally lean towards
being higher log levels than they necessarily need to be, as they
should be exceedingly rare, if only because they require
confirmation of an on-chain transaction.
This updates a number of log sites in channel and channelmanager to
* Be a bit more verbose at the TRACE level,
* Move some error/useful messages to the ERROR/WARN/INFO level,
* Add new logs to always log once at the DEBUG level when we
send/receive a commitment_signed (with some extra data),
* Include the channel id being operated on in more log messages.
We very often receive duplicate gossip messages, which now causes us
to log at the DEBUG level, which is almost certainly not what a
user wants. Instead, we add a new form of ErrorAction which causes
us to only log at the TRACE level.
For log entries which may have a variable level, we can't call an
arbitrary macro and need to be able to pass an explicit level. This
does so without breaking the compile-time disabling of certain log
levels.
Further, we "fix" the comparison order of log levels to make more
significant levels sort "higher", which implicitly makes more sense
than sorting "lower".
Finally, we remove the "Off" log level as no log entry should ever
be logged at the "Off" level - that would be nonsensical.
This much more consistently logs information about messages
sent/received, including logging the full messages being
sent/received at the TRACE log level. Many other log messages which
are more often of interest were moved to the DEBUG log level.
We had a client application which provided inconsistent monitor
state when deserializing a ChannelManager, resulting in opaque and
generic "InvalidData" deserialization failures. Instead, we log
some informative (and appropriately scary) warning messages in
such cases.
When a peer sends us the routing graph, it may include gossip
messages for our channels, despite it not being a party to them.
This is completely fine, but we currently print a somewhat-scary
looking log messages in these cases, eg:
```
ERROR [lightning::ln::channelmanager:4104] Got a message for a channel from the wrong node!
TRACE [lightning::ln::peer_handler:1267] Handling SendErrorMessage HandleError event in peer_handler for node ... with message Got a message for a channel from the wrong node!
```
Instead, we should simply not consider this an "error" condition
and stay silent.
The only practical way to meet this requirement is to block
disconnect_socket until any pending events are fully processed,
leading to this trivial deadlock:
* Thread 1: select() woken up due to a read event
* Thread 2: Event processing causes a disconnect_socket call to
fire while the PeerManager lock is held.
* Thread 2: disconnect_socket blocks until the read event in
thread 1 completes.
* Thread 1: bytes are read from the socket and
PeerManager::read_event is called, waiting on the lock
still held by thread 2.
There isn't a trivial way to address this deadlock without simply
making the final read_event call return immediately, which we do
here. This also implies that users can freely call event methods
after disconnect_socket, but only so far as the socket descriptor
is different from any later socket descriptor (ie until the file
descriptor is re-used).
`Julian Knutsen <julianknutsen@users.noreply.github.com>` pointed
out in a previous discussion that `read_event` can reenter user
code despite the documentation stating explicitly that it will not.
This was addressed in #456 by simply codifying the reentrancy, but
its somewhat simpler to just drop the `do_attempt_write_data` call.
Ideally we could land most of Julian's work, but its still in need
of substantial git history cleanup to get it in a reviewable state
and this solves the immediate issue.
We can never assume that messages were reliably delivered whether
we placed them in the socket or not, so there isn't a lot of use in
explicitly handling the case that a peer was not connected when we
went to send it a message.
Two TODOs are left for the generation of a `FundingAbandoned` (or
similar) event, though it ultimately belongs in `ChannelManager`.
Latest rustc warns that "this URL is not a hyperlink" and notes that
"bare URLs are not automatically turned into clickable links". This
resolves those warnings.
Thanks to Joshua Nelson for pointing out the correct syntax for
this.
Lightning invoices allow for zero or more multi-hop route hints. Update
get_route's interface to accept such hints, although only the last hop
from each is used for the time being.
Moves RouteHint from lightning-invoice crate to lightning crate. Adds a
PrivateRoute wrapper around RouteHint for use in lightning-invoice.
VecReadWrapper is only used in TLVs so there is no need to prepend
a length before writing/reading the objects - we can instead simply
read until we reach the end of the TLV stream.
This substantially improves deserialization performance when LLVM
decides not to inline many short methods, eg when not building
with LTO/codegen-units=1.
Even with the default bench params of LTO/codegen-units=1, the
serialization benchmarks on an Intel 2687W v3 take:
test routing::network_graph::benches::read_network_graph ... bench: 1,955,616,225 ns/iter (+/- 4,135,777)
test routing::network_graph::benches::write_network_graph ... bench: 165,905,275 ns/iter (+/- 118,798)
With the new `serialized_length()` method potentially being
significantly more efficient than `LengthCalculatingWriter`, this
commit ensures we call `serialized_length()` when calculating
length of a larger struct.
Specifically, prior to this commit a call to
`serialized_length()` on a large object serialized with
`impl_writeable`, `impl_writeable_len_match`, or
`encode_varint_length_prefixed_tlv` (and
`impl_writeable_tlv_based`) would always serialize all inner fields
of that object using `LengthCalculatingWriter`. This would ignore
any `serialized_length()` overrides by inner fields. Instead, we
override `serialized_length()` on all of the above by calculating
the serialized size using calls to `serialized_length()` on inner
fields.
Further, writes to `LengthCalculatingWriter` should never fail as
its `write` method never returns an error. Thus, any write failures
indicate a bug in an object's write method or in our
object-creation sanity checking. We `.expect()` such write calls
here.
As of this commit, on an Intel 2687W v3, the serialization
benchmarks take:
test routing::network_graph::benches::read_network_graph ... bench: 2,039,451,296 ns/iter (+/- 4,329,821)
test routing::network_graph::benches::write_network_graph ... bench: 166,685,412 ns/iter (+/- 352,537)
When writing out libsecp256k1 objects during serialization in a
TLV, we potentially calculate the TLV length twice before
performing the actual serialization (once when calculating the
total TLV-stream length and once when calculating the length of the
secp256k1-object-containing TLV). Because the lengths of secp256k1
objects is a constant, we'd ideally like LLVM to entirely optimize
out those calls and simply know the expected length. However,
without cross-language LTO, there is no way for LLVM to verify that
there are no side-effects of the calls to libsecp256k1, leaving
LLVM with no way to optimize them out.
This commit adds a new method to `Writeable` which returns the
length of an object once serialized. It is implemented by default
using `LengthCalculatingWriter` (which LLVM generally optimizes out
for Rust objects) and overrides it for libsecp256k1 objects.
As of this commit, on an Intel 2687W v3, the serialization
benchmarks take:
test routing::network_graph::benches::read_network_graph ... bench: 2,035,402,164 ns/iter (+/- 1,855,357)
test routing::network_graph::benches::write_network_graph ... bench: 308,235,267 ns/iter (+/- 140,202)
