From 98340dc25371eeae2854bebf6ac0f4faba0d2830 Mon Sep 17 00:00:00 2001 From: Matt Corallo Date: Tue, 6 Feb 2024 23:13:08 +0000 Subject: [PATCH 1/3] Use `{}`, not `{:?}` for `PublicKey` logging The `Debug` serialization of `PublicKey`s includes both the X and Y coordinate, which isn't something most of our users deal with. Instead, logging using `Display` gives users the keys they're used to. --- lightning/src/onion_message/messenger.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/lightning/src/onion_message/messenger.rs b/lightning/src/onion_message/messenger.rs index 37de5504532..c6b92570496 100644 --- a/lightning/src/onion_message/messenger.rs +++ b/lightning/src/onion_message/messenger.rs @@ -766,7 +766,7 @@ where }, Ok(SendSuccess::BufferedAwaitingConnection(node_id)) => { log_trace!( - self.logger, "Buffered onion message waiting on peer connection {}: {:?}", + self.logger, "Buffered onion message waiting on peer connection {}: {}", log_suffix, node_id ); }, @@ -957,7 +957,7 @@ where Ok(PeeledOnion::Forward(next_node_id, onion_message)) => { let mut message_recipients = self.message_recipients.lock().unwrap(); if outbound_buffer_full(&next_node_id, &message_recipients) { - log_trace!(self.logger, "Dropping forwarded onion message to peer {:?}: outbound buffer full", next_node_id); + log_trace!(self.logger, "Dropping forwarded onion message to peer {}: outbound buffer full", next_node_id); return } @@ -974,7 +974,7 @@ where log_trace!(self.logger, "Forwarding an onion message to peer {}", next_node_id); }, _ => { - log_trace!(self.logger, "Dropping forwarded onion message to disconnected peer {:?}", next_node_id); + log_trace!(self.logger, "Dropping forwarded onion message to disconnected peer {}", next_node_id); return }, } From b29033659f0b9999e48bf94fa6de9f17384d1ced Mon Sep 17 00:00:00 2001 From: Matt Corallo Date: Tue, 6 Feb 2024 23:17:50 +0000 Subject: [PATCH 2/3] Add `PersistenceNotifierGuard` take to offer/refund payments This resolves an issue where offer and refund payments get delayed while we wait for the `invoice_request`/`invoice` onion messages to get sent. It further ensures we're likely to have the `ChannelManager` persisted with the new payment info after initiating the send/receive. --- lightning/src/ln/channelmanager.rs | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/lightning/src/ln/channelmanager.rs b/lightning/src/ln/channelmanager.rs index 7bd395f999a..16ca44c3428 100644 --- a/lightning/src/ln/channelmanager.rs +++ b/lightning/src/ln/channelmanager.rs @@ -7755,6 +7755,8 @@ macro_rules! create_refund_builder { ($self: ident, $builder: ty) => { .absolute_expiry(absolute_expiry) .path(path); + let _persistence_guard = PersistenceNotifierGuard::notify_on_drop($self); + let expiration = StaleExpiration::AbsoluteTimeout(absolute_expiry); $self.pending_outbound_payments .add_new_awaiting_invoice( @@ -7870,6 +7872,8 @@ where let invoice_request = builder.build_and_sign()?; let reply_path = self.create_blinded_path().map_err(|_| Bolt12SemanticError::MissingPaths)?; + let _persistence_guard = PersistenceNotifierGuard::notify_on_drop(self); + let expiration = StaleExpiration::TimerTicks(1); self.pending_outbound_payments .add_new_awaiting_invoice( @@ -7937,6 +7941,8 @@ where return Err(Bolt12SemanticError::UnsupportedChain); } + let _persistence_guard = PersistenceNotifierGuard::notify_on_drop(self); + match self.create_inbound_payment(Some(amount_msats), relative_expiry, None) { Ok((payment_hash, payment_secret)) => { let payment_paths = self.create_blinded_payment_paths(amount_msats, payment_secret) From 29984a78acfbc07c52637535d02be7ac9047906c Mon Sep 17 00:00:00 2001 From: Matt Corallo Date: Wed, 7 Feb 2024 01:19:09 +0000 Subject: [PATCH 3/3] Use structured logging where appropriate in `OnionMessenger` --- lightning/src/onion_message/messenger.rs | 41 ++++++++++++++++-------- 1 file changed, 27 insertions(+), 14 deletions(-) diff --git a/lightning/src/onion_message/messenger.rs b/lightning/src/onion_message/messenger.rs index c6b92570496..9f6c5cb4352 100644 --- a/lightning/src/onion_message/messenger.rs +++ b/lightning/src/onion_message/messenger.rs @@ -28,7 +28,7 @@ use super::packet::OnionMessageContents; use super::packet::ParsedOnionMessageContents; use super::offers::OffersMessageHandler; use super::packet::{BIG_PACKET_HOP_DATA_LEN, ForwardControlTlvs, Packet, Payload, ReceiveControlTlvs, SMALL_PACKET_HOP_DATA_LEN}; -use crate::util::logger::Logger; +use crate::util::logger::{Logger, WithContext}; use crate::util::ser::Writeable; use core::fmt; @@ -748,25 +748,31 @@ where &self, contents: T, destination: Destination, reply_path: Option, log_suffix: fmt::Arguments ) -> Result { + let mut logger = WithContext::from(&self.logger, None, None); let result = self.find_path(destination) - .and_then(|path| self.enqueue_onion_message(path, contents, reply_path, log_suffix)); + .and_then(|path| { + let first_hop = path.intermediate_nodes.get(0).map(|p| *p); + logger = WithContext::from(&self.logger, first_hop, None); + self.enqueue_onion_message(path, contents, reply_path, log_suffix) + }); match result.as_ref() { Err(SendError::GetNodeIdFailed) => { - log_warn!(self.logger, "Unable to retrieve node id {}", log_suffix); + log_warn!(logger, "Unable to retrieve node id {}", log_suffix); }, Err(SendError::PathNotFound) => { - log_trace!(self.logger, "Failed to find path {}", log_suffix); + log_trace!(logger, "Failed to find path {}", log_suffix); }, Err(e) => { - log_trace!(self.logger, "Failed sending onion message {}: {:?}", log_suffix, e); + log_trace!(logger, "Failed sending onion message {}: {:?}", log_suffix, e); }, Ok(SendSuccess::Buffered) => { - log_trace!(self.logger, "Buffered onion message {}", log_suffix); + log_trace!(logger, "Buffered onion message {}", log_suffix); }, Ok(SendSuccess::BufferedAwaitingConnection(node_id)) => { log_trace!( - self.logger, "Buffered onion message waiting on peer connection {}: {}", + logger, + "Buffered onion message waiting on peer connection {}: {}", log_suffix, node_id ); }, @@ -925,12 +931,13 @@ where OMH::Target: OffersMessageHandler, CMH::Target: CustomOnionMessageHandler, { - fn handle_onion_message(&self, _peer_node_id: &PublicKey, msg: &OnionMessage) { + fn handle_onion_message(&self, peer_node_id: &PublicKey, msg: &OnionMessage) { + let logger = WithContext::from(&self.logger, Some(*peer_node_id), None); match self.peel_onion_message(msg) { Ok(PeeledOnion::Receive(message, path_id, reply_path)) => { log_trace!( - self.logger, - "Received an onion message with path_id {:02x?} and {} reply_path: {:?}", + logger, + "Received an onion message with path_id {:02x?} and {} reply_path: {:?}", path_id, if reply_path.is_some() { "a" } else { "no" }, message); match message { @@ -957,7 +964,10 @@ where Ok(PeeledOnion::Forward(next_node_id, onion_message)) => { let mut message_recipients = self.message_recipients.lock().unwrap(); if outbound_buffer_full(&next_node_id, &message_recipients) { - log_trace!(self.logger, "Dropping forwarded onion message to peer {}: outbound buffer full", next_node_id); + log_trace!( + logger, + "Dropping forwarded onion message to peer {}: outbound buffer full", + next_node_id); return } @@ -971,16 +981,19 @@ where e.get(), OnionMessageRecipient::ConnectedPeer(..) ) => { e.get_mut().enqueue_message(onion_message); - log_trace!(self.logger, "Forwarding an onion message to peer {}", next_node_id); + log_trace!(logger, "Forwarding an onion message to peer {}", next_node_id); }, _ => { - log_trace!(self.logger, "Dropping forwarded onion message to disconnected peer {}", next_node_id); + log_trace!( + logger, + "Dropping forwarded onion message to disconnected peer {}", + next_node_id); return }, } }, Err(e) => { - log_error!(self.logger, "Failed to process onion message {:?}", e); + log_error!(logger, "Failed to process onion message {:?}", e); } } }