Skip to content

Commit

Permalink
Changes to logger and macro logger
Browse files Browse the repository at this point in the history
  • Loading branch information
@henghonglee
henghonglee committed May 23, 2023
1 parent 6775b95 commit 14f187c
Show file tree
Hide file tree
Showing 20 changed files with 504 additions and 500 deletions.
40 changes: 20 additions & 20 deletions lightning-background-processor/src/lib.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -272,9 +272,9 @@ macro_rules! define_run_body {
$loop_exit_check: expr, $await: expr, $get_timer: expr, $timer_elapsed: expr,
$check_slow_await: expr)
=> { {
log_trace!($logger, "Calling ChannelManager's timer_tick_occurred on startup");
log_trace!($logger, None, None, "Calling ChannelManager's timer_tick_occurred on startup");
$channel_manager.timer_tick_occurred();
log_trace!($logger, "Rebroadcasting monitor's pending claims on startup");
log_trace!($logger, None, None, "Rebroadcasting monitor's pending claims on startup");
$chain_monitor.rebroadcast_pending_claims();

let mut last_freshness_call = $get_timer(FRESHNESS_TIMER);
Expand Down Expand Up @@ -303,7 +303,7 @@ macro_rules! define_run_body {

// Exit the loop if the background processor was requested to stop.
if $loop_exit_check {
log_trace!($logger, "Terminating background processor.");
log_trace!($logger, None, None, "Terminating background processor.");
break;
}

Expand All @@ -316,17 +316,17 @@ macro_rules! define_run_body {

// Exit the loop if the background processor was requested to stop.
if $loop_exit_check {
log_trace!($logger, "Terminating background processor.");
log_trace!($logger, None, None, "Terminating background processor.");
break;
}

if updates_available {
log_trace!($logger, "Persisting ChannelManager...");
log_trace!($logger, None, None, "Persisting ChannelManager...");
$persister.persist_manager(&*$channel_manager)?;
log_trace!($logger, "Done persisting ChannelManager.");
log_trace!($logger, None, None, "Done persisting ChannelManager.");
}
if $timer_elapsed(&mut last_freshness_call, FRESHNESS_TIMER) {
log_trace!($logger, "Calling ChannelManager's timer_tick_occurred");
log_trace!($logger, None, None, "Calling ChannelManager's timer_tick_occurred");
$channel_manager.timer_tick_occurred();
last_freshness_call = $get_timer(FRESHNESS_TIMER);
}
Expand All @@ -343,11 +343,11 @@ macro_rules! define_run_body {
// may call Bitcoin Core RPCs during event handling, which very often takes
// more than a handful of seconds to complete, and shouldn't disconnect all our
// peers.
log_trace!($logger, "100ms sleep took more than a second, disconnecting peers.");
log_trace!($logger, None, None, "100ms sleep took more than a second, disconnecting peers.");
$peer_manager.as_ref().disconnect_all_peers();
last_ping_call = $get_timer(PING_TIMER);
} else if $timer_elapsed(&mut last_ping_call, PING_TIMER) {
log_trace!($logger, "Calling PeerManager's timer_tick_occurred");
log_trace!($logger, None, None, "Calling PeerManager's timer_tick_occurred");
$peer_manager.as_ref().timer_tick_occurred();
last_ping_call = $get_timer(PING_TIMER);
}
Expand All @@ -367,16 +367,16 @@ macro_rules! define_run_body {
// The network graph must not be pruned while rapid sync completion is pending
if let Some(network_graph) = $gossip_sync.prunable_network_graph() {
#[cfg(feature = "std")] {
log_trace!($logger, "Pruning and persisting network graph.");
log_trace!($logger, None, None, "Pruning and persisting network graph.");
network_graph.remove_stale_channels_and_tracking();
}
#[cfg(not(feature = "std"))] {
log_warn!($logger, "Not pruning network graph, consider enabling `std` or doing so manually with remove_stale_channels_and_tracking_with_time.");
log_trace!($logger, "Persisting network graph.");
log_warn!($logger, None, None, "Not pruning network graph, consider enabling `std` or doing so manually with remove_stale_channels_and_tracking_with_time.");
log_trace!($logger, None, None, "Persisting network graph.");
}

if let Err(e) = $persister.persist_graph(network_graph) {
log_error!($logger, "Error: Failed to persist network graph, check your disk and permissions {}", e)
log_error!($logger, None, None, "Error: Failed to persist network graph, check your disk and permissions {}", e)
}

have_pruned = true;
Expand All @@ -387,16 +387,16 @@ macro_rules! define_run_body {

if $timer_elapsed(&mut last_scorer_persist_call, SCORER_PERSIST_TIMER) {
if let Some(ref scorer) = $scorer {
log_trace!($logger, "Persisting scorer");
log_trace!($logger, None, None, "Persisting scorer");
if let Err(e) = $persister.persist_scorer(&scorer) {
log_error!($logger, "Error: Failed to persist scorer, check your disk and permissions {}", e)
log_error!($logger, None, None, "Error: Failed to persist scorer, check your disk and permissions {}", e)
}
}
last_scorer_persist_call = $get_timer(SCORER_PERSIST_TIMER);
}

if $timer_elapsed(&mut last_rebroadcast_call, REBROADCAST_TIMER) {
log_trace!($logger, "Rebroadcasting monitor's pending claims");
log_trace!($logger, None, None, "Rebroadcasting monitor's pending claims");
$chain_monitor.rebroadcast_pending_claims();
last_rebroadcast_call = $get_timer(REBROADCAST_TIMER);
}
Expand Down Expand Up @@ -633,9 +633,9 @@ where
}
if let Some(ref scorer) = scorer {
if update_scorer(scorer, &event) {
log_trace!(logger, "Persisting scorer after update");
log_trace!(logger, None, None, "Persisting scorer after update");
if let Err(e) = persister.persist_scorer(&scorer) {
log_error!(logger, "Error: Failed to persist scorer, check your disk and permissions {}", e)
log_error!(logger, None, None, "Error: Failed to persist scorer, check your disk and permissions {}", e)
}
}
}
Expand Down Expand Up @@ -768,9 +768,9 @@ impl BackgroundProcessor {
}
if let Some(ref scorer) = scorer {
if update_scorer(scorer, &event) {
log_trace!(logger, "Persisting scorer after update");
log_trace!(logger, None, None, "Persisting scorer after update");
if let Err(e) = persister.persist_scorer(&scorer) {
log_error!(logger, "Error: Failed to persist scorer, check your disk and permissions {}", e)
log_error!(logger, None, None, "Error: Failed to persist scorer, check your disk and permissions {}", e)
}
}
}
Expand Down
26 changes: 13 additions & 13 deletions lightning-invoice/src/utils.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -187,7 +187,7 @@ where
.map_err(|_| SignOrCreationError::CreationError(CreationError::InvalidAmount))?
};

log_trace!(logger, "Creating phantom invoice from {} participating nodes with payment hash {}",
log_trace!(logger, None, None, "Creating phantom invoice from {} participating nodes with payment hash {}",
phantom_route_hints.len(), log_bytes!(payment_hash.0));

let mut invoice = invoice
Expand Down Expand Up @@ -236,7 +236,7 @@ where
let mut phantom_hints: Vec<Vec<RouteHint>> = Vec::new();

for PhantomRouteHints { channels, phantom_scid, real_node_pubkey } in phantom_route_hints {
log_trace!(logger, "Generating phantom route hints for node {}",
log_trace!(logger, None, None, "Generating phantom route hints for node {}",
log_pubkey!(real_node_pubkey));
let mut route_hints = sort_and_filter_channels(channels, amt_msat, &logger);

Expand Down Expand Up @@ -513,7 +513,7 @@ fn _create_invoice_from_channelmanager_and_duration_since_epoch_with_payment_has
return Err(SignOrCreationError::CreationError(CreationError::MinFinalCltvExpiryDeltaTooShort));
}

log_trace!(logger, "Creating invoice with payment hash {}", log_bytes!(payment_hash.0));
log_trace!(logger, None, None, "Creating invoice with payment hash {}", log_bytes!(payment_hash.0));

let invoice = match description {
InvoiceDescription::Direct(description) => {
Expand Down Expand Up @@ -584,10 +584,10 @@ fn sort_and_filter_channels<L: Deref>(
let mut online_min_capacity_channel_exists = false;
let mut has_pub_unconf_chan = false;

log_trace!(logger, "Considering {} channels for invoice route hints", channels.len());
log_trace!(logger, None, None, "Considering {} channels for invoice route hints", channels.len());
for channel in channels.into_iter().filter(|chan| chan.is_channel_ready) {
if channel.get_inbound_payment_scid().is_none() || channel.counterparty.forwarding_info.is_none() {
log_trace!(logger, "Ignoring channel {} for invoice route hints", log_bytes!(channel.channel_id));
log_trace!(logger, None, None, "Ignoring channel {} for invoice route hints", log_bytes!(channel.channel_id));
continue;
}

Expand All @@ -600,15 +600,15 @@ fn sort_and_filter_channels<L: Deref>(
} else {
// If any public channel exists, return no hints and let the sender
// look at the public channels instead.
log_trace!(logger, "Not including channels in invoice route hints on account of public channel {}",
log_trace!(logger, None, None, "Not including channels in invoice route hints on account of public channel {}",
log_bytes!(channel.channel_id));
return vec![]
}
}

if channel.inbound_capacity_msat >= min_inbound_capacity {
if !min_capacity_channel_exists {
log_trace!(logger, "Channel with enough inbound capacity exists for invoice route hints");
log_trace!(logger, None, None, "Channel with enough inbound capacity exists for invoice route hints");
min_capacity_channel_exists = true;
}

Expand All @@ -618,7 +618,7 @@ fn sort_and_filter_channels<L: Deref>(
}

if channel.is_usable && !online_channel_exists {
log_trace!(logger, "Channel with connected peer exists for invoice route hints");
log_trace!(logger, None, None, "Channel with connected peer exists for invoice route hints");
online_channel_exists = true;
}

Expand All @@ -638,7 +638,7 @@ fn sort_and_filter_channels<L: Deref>(
let new_channel_preferable = channel.is_public == entry.get().is_public && !prefer_current;

if new_now_public || new_channel_preferable {
log_trace!(logger,
log_trace!(logger, None, None,
"Preferring counterparty {} channel {} (SCID {:?}, {} msats) over {} (SCID {:?}, {} msats) for invoice route hints",
log_pubkey!(channel.counterparty.node_id),
log_bytes!(channel.channel_id), channel.short_channel_id,
Expand All @@ -647,7 +647,7 @@ fn sort_and_filter_channels<L: Deref>(
current_max_capacity);
entry.insert(channel);
} else {
log_trace!(logger,
log_trace!(logger, None, None,
"Preferring counterparty {} channel {} (SCID {:?}, {} msats) over {} (SCID {:?}, {} msats) for invoice route hints",
log_pubkey!(channel.counterparty.node_id),
log_bytes!(entry.get().channel_id), entry.get().short_channel_id,
Expand Down Expand Up @@ -703,14 +703,14 @@ fn sort_and_filter_channels<L: Deref>(
} else { true };

if include_channel {
log_trace!(logger, "Including channel {} in invoice route hints",
log_trace!(logger, None, None, "Including channel {} in invoice route hints",
log_bytes!(channel.channel_id));
} else if !has_enough_capacity {
log_trace!(logger, "Ignoring channel {} without enough capacity for invoice route hints",
log_trace!(logger, None, None, "Ignoring channel {} without enough capacity for invoice route hints",
log_bytes!(channel.channel_id));
} else {
debug_assert!(!channel.is_usable || (has_pub_unconf_chan && !channel.is_public));
log_trace!(logger, "Ignoring channel {} with disconnected peer",
log_trace!(logger, None, None, "Ignoring channel {} with disconnected peer",
log_bytes!(channel.channel_id));
}

Expand Down
16 changes: 8 additions & 8 deletions lightning-rapid-gossip-sync/src/processing.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,7 @@ impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L
mut read_cursor: &mut R,
current_time_unix: Option<u64>
) -> Result<u32, GraphSyncError> {
log_trace!(self.logger, "Processing RGS data...");
log_trace!(self.logger, None, None, "Processing RGS data...");
let mut prefix = [0u8; 4];
read_cursor.read_exact(&mut prefix)?;

Expand Down Expand Up @@ -112,7 +112,7 @@ impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L
let node_id_1 = node_ids[node_id_1_index.0 as usize];
let node_id_2 = node_ids[node_id_2_index.0 as usize];

log_gossip!(self.logger, "Adding channel {} from RGS announcement at {}",
log_gossip!(self.logger, None, None, "Adding channel {} from RGS announcement at {}",
short_channel_id, latest_seen_timestamp);

let announcement_result = network_graph.add_channel_from_partial_announcement(
Expand All @@ -126,7 +126,7 @@ impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L
if let ErrorAction::IgnoreDuplicateGossip = lightning_error.action {
// everything is fine, just a duplicate channel announcement
} else {
log_warn!(self.logger, "Failed to process channel announcement: {:?}", lightning_error);
log_warn!(self.logger, None, None, "Failed to process channel announcement: {:?}", lightning_error);
return Err(lightning_error.into());
}
}
Expand All @@ -135,7 +135,7 @@ impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L
previous_scid = 0; // updates start at a new scid

let update_count: u32 = Readable::read(read_cursor)?;
log_debug!(self.logger, "Processing RGS update from {} with {} nodes, {} channel announcements and {} channel updates.",
log_debug!(self.logger, None, None, "Processing RGS update from {} with {} nodes, {} channel announcements and {} channel updates.",
latest_seen_timestamp, node_id_count, announcement_count, update_count);
if update_count == 0 {
return Ok(latest_seen_timestamp);
Expand Down Expand Up @@ -188,7 +188,7 @@ impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L
synthetic_update.fee_base_msat = directional_info.fees.base_msat;
synthetic_update.fee_proportional_millionths = directional_info.fees.proportional_millionths;
} else {
log_trace!(self.logger,
log_trace!(self.logger, None, None,
"Skipping application of channel update for chan {} with flags {} as original data is missing.",
short_channel_id, channel_flags);
skip_update_for_unknown_channel = true;
Expand Down Expand Up @@ -224,13 +224,13 @@ impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L
continue;
}

log_gossip!(self.logger, "Updating channel {} with flags {} from RGS announcement at {}",
log_gossip!(self.logger, None, None, "Updating channel {} with flags {} from RGS announcement at {}",
short_channel_id, channel_flags, latest_seen_timestamp);
match network_graph.update_channel_unsigned(&synthetic_update) {
Ok(_) => {},
Err(LightningError { action: ErrorAction::IgnoreDuplicateGossip, .. }) => {},
Err(LightningError { action: ErrorAction::IgnoreAndLog(level), err }) => {
log_given_level!(self.logger, level, "Failed to apply channel update: {:?}", err);
log_given_level!(self.logger, level, None, None, "Failed to apply channel update: {:?}", err);
},
Err(LightningError { action: ErrorAction::IgnoreError, .. }) => {},
Err(e) => return Err(e.into()),
Expand All @@ -244,7 +244,7 @@ impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L
}

self.is_initial_sync_complete.store(true, Ordering::Release);
log_trace!(self.logger, "Done processing RGS data from {}", latest_seen_timestamp);
log_trace!(self.logger, None, None, "Done processing RGS data from {}", latest_seen_timestamp);
Ok(latest_seen_timestamp)
}
}
Expand Down
20 changes: 10 additions & 10 deletions lightning-transaction-sync/src/esplora.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -89,7 +89,7 @@ where
#[cfg(feature = "async-interface")]
let mut sync_state = self.sync_state.lock().await;

log_info!(self.logger, "Starting transaction sync.");
log_info!(self.logger, None, None, "Starting transaction sync.");

let mut tip_hash = maybe_await!(self.client.get_tip_hash())?;

Expand Down Expand Up @@ -120,7 +120,7 @@ where
},
Err(err) => {
// (Semi-)permanent failure, retry later.
log_error!(self.logger, "Failed during transaction sync, aborting.");
log_error!(self.logger, None, None, "Failed during transaction sync, aborting.");
sync_state.pending_sync = true;
return Err(TxSyncError::from(err));
}
Expand All @@ -130,7 +130,7 @@ where
Ok(()) => {}
Err(InternalError::Inconsistency) => {
// Immediately restart syncing when we encounter any inconsistencies.
log_debug!(self.logger, "Encountered inconsistency during transaction sync, restarting.");
log_debug!(self.logger, None, None, "Encountered inconsistency during transaction sync, restarting.");
sync_state.pending_sync = true;
continue;
}
Expand Down Expand Up @@ -160,13 +160,13 @@ where
}
Err(InternalError::Inconsistency) => {
// Immediately restart syncing when we encounter any inconsistencies.
log_debug!(self.logger, "Encountered inconsistency during transaction sync, restarting.");
log_debug!(self.logger, None, None, "Encountered inconsistency during transaction sync, restarting.");
sync_state.pending_sync = true;
continue;
}
Err(err) => {
// (Semi-)permanent failure, retry later.
log_error!(self.logger, "Failed during transaction sync, aborting.");
log_error!(self.logger, None, None, "Failed during transaction sync, aborting.");
sync_state.pending_sync = true;
return Err(TxSyncError::from(err));
}
Expand All @@ -175,7 +175,7 @@ where
sync_state.pending_sync = false;
}
}
log_info!(self.logger, "Finished transaction sync.");
log_info!(self.logger, None, None, "Finished transaction sync.");
Ok(())
}

Expand Down Expand Up @@ -273,7 +273,7 @@ where
let block_hash = block_header.block_hash();
if let Some(expected_block_hash) = expected_block_hash {
if expected_block_hash != block_hash {
log_trace!(self.logger, "Inconsistency: Tx {} expected in block {}, but is confirmed in {}", txid, expected_block_hash, block_hash);
log_trace!(self.logger, None, None, "Inconsistency: Tx {} expected in block {}, but is confirmed in {}", txid, expected_block_hash, block_hash);
return Err(InternalError::Inconsistency);
}
}
Expand All @@ -282,7 +282,7 @@ where
let mut indexes = Vec::new();
let _ = merkle_block.txn.extract_matches(&mut matches, &mut indexes);
if indexes.len() != 1 || matches.len() != 1 || matches[0] != *txid {
log_error!(self.logger, "Retrieved Merkle block for txid {} doesn't match expectations. This should not happen. Please verify server integrity.", txid);
log_error!(self.logger, None, None, "Retrieved Merkle block for txid {} doesn't match expectations. This should not happen. Please verify server integrity.", txid);
return Err(InternalError::Failed);
}

Expand All @@ -299,7 +299,7 @@ where
} else {
// If any previously-confirmed block suddenly is no longer confirmed, we found
// an inconsistency and should start over.
log_trace!(self.logger, "Inconsistency: Tx {} was unconfirmed during syncing.", txid);
log_trace!(self.logger, None, None, "Inconsistency: Tx {} was unconfirmed during syncing.", txid);
return Err(InternalError::Inconsistency);
}
}
Expand Down Expand Up @@ -330,7 +330,7 @@ where

unconfirmed_txs.push(txid);
} else {
log_error!(self.logger, "Untracked confirmation of funding transaction. Please ensure none of your channels had been created with LDK prior to version 0.0.113!");
log_error!(self.logger, None, None, "Untracked confirmation of funding transaction. Please ensure none of your channels had been created with LDK prior to version 0.0.113!");
panic!("Untracked confirmation of funding transaction. Please ensure none of your channels had been created with LDK prior to version 0.0.113!");
}
}
Expand Down
Loading

0 comments on commit 14f187c

Please sign in to comment.