From 46cdcc541c7d07d2119c2bcc3f6ac085eed7318e Mon Sep 17 00:00:00 2001 From: optout <13562139+optout21@users.noreply.github.com> Date: Thu, 10 Aug 2023 08:09:36 +0200 Subject: [PATCH] Simplifying logging/formatting by adding Display trait --- lightning-invoice/src/utils.rs | 18 ++-- lightning/src/chain/channelmonitor.rs | 4 +- lightning/src/ln/channel.rs | 106 ++++++++++++---------- lightning/src/ln/channelmanager.rs | 92 +++++++++---------- lightning/src/ln/functional_test_utils.rs | 2 +- lightning/src/ln/functional_tests.rs | 4 +- lightning/src/ln/payment_tests.rs | 2 +- lightning/src/ln/peer_handler.rs | 44 ++++----- lightning/src/util/macro_logger.rs | 8 +- 9 files changed, 144 insertions(+), 136 deletions(-) diff --git a/lightning-invoice/src/utils.rs b/lightning-invoice/src/utils.rs index 5591d4e8f39..87ef582412c 100644 --- a/lightning-invoice/src/utils.rs +++ b/lightning-invoice/src/utils.rs @@ -627,7 +627,7 @@ where log_trace!(logger, "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.bytes()[..])); + log_trace!(logger, "Ignoring channel {} for invoice route hints", &channel.channel_id); continue; } @@ -641,7 +641,7 @@ where // 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_bytes!(channel.channel_id.bytes()[..])); + &channel.channel_id); return vec![].into_iter().take(MAX_CHANNEL_HINTS).map(route_hint_from_channel); } } @@ -681,18 +681,18 @@ where log_trace!(logger, "Preferring counterparty {} channel {} (SCID {:?}, {} msats) over {} (SCID {:?}, {} msats) for invoice route hints", log_pubkey!(channel.counterparty.node_id), - log_bytes!(channel.channel_id.bytes()[..]), channel.short_channel_id, + &channel.channel_id, channel.short_channel_id, channel.inbound_capacity_msat, - log_bytes!(entry.get().channel_id.bytes()[..]), entry.get().short_channel_id, + &entry.get().channel_id, entry.get().short_channel_id, current_max_capacity); entry.insert(channel); } else { log_trace!(logger, "Preferring counterparty {} channel {} (SCID {:?}, {} msats) over {} (SCID {:?}, {} msats) for invoice route hints", log_pubkey!(channel.counterparty.node_id), - log_bytes!(entry.get().channel_id.bytes()[..]), entry.get().short_channel_id, + &entry.get().channel_id, entry.get().short_channel_id, current_max_capacity, - log_bytes!(channel.channel_id.bytes()[..]), channel.short_channel_id, + &channel.channel_id, channel.short_channel_id, channel.inbound_capacity_msat); } } @@ -731,14 +731,14 @@ where if include_channel { log_trace!(logger, "Including channel {} in invoice route hints", - log_bytes!(channel.channel_id.bytes()[..])); + &channel.channel_id); } else if !has_enough_capacity { log_trace!(logger, "Ignoring channel {} without enough capacity for invoice route hints", - log_bytes!(channel.channel_id.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_bytes!(channel.channel_id.bytes()[..])); + &channel.channel_id); } include_channel diff --git a/lightning/src/chain/channelmonitor.rs b/lightning/src/chain/channelmonitor.rs index d8f3d9542c7..dccfe1ae7bb 100644 --- a/lightning/src/chain/channelmonitor.rs +++ b/lightning/src/chain/channelmonitor.rs @@ -2525,7 +2525,7 @@ impl ChannelMonitorImpl { } } else if !self.holder_tx_signed { log_error!(logger, "WARNING: You have a potentially-unsafe holder commitment transaction available to broadcast"); - log_error!(logger, " in channel monitor for channel {}!", log_bytes!(self.funding_info.0.to_channel_id().bytes()[..])); + log_error!(logger, " in channel monitor for channel {}!", &self.funding_info.0.to_channel_id()); log_error!(logger, " Read the docs for ChannelMonitor::get_latest_holder_commitment_txn and take manual action!"); } else { // If we generated a MonitorEvent::CommitmentTxConfirmed, the ChannelManager @@ -3183,7 +3183,7 @@ impl ChannelMonitorImpl { if prevout.txid == self.funding_info.0.txid && prevout.vout == self.funding_info.0.index as u32 { let mut balance_spendable_csv = None; log_info!(logger, "Channel {} closed by funding output spend in txid {}.", - log_bytes!(self.funding_info.0.to_channel_id().bytes()[..]), txid); + &self.funding_info.0.to_channel_id(), txid); self.funding_spend_seen = true; let mut commitment_tx_to_counterparty_output = None; if (tx.input[0].sequence.0 >> 8*3) as u8 == 0x80 && (tx.lock_time.0 >> 8*3) as u8 == 0x20 { diff --git a/lightning/src/ln/channel.rs b/lightning/src/ln/channel.rs index fe64413e0c1..ba368b03f85 100644 --- a/lightning/src/ln/channel.rs +++ b/lightning/src/ln/channel.rs @@ -662,13 +662,23 @@ impl Writeable for ChannelId { } impl Readable for ChannelId { - // TODO add serialize-deserialize unit test fn read(r: &mut R) -> Result { let buf: [u8; 32] = Readable::read(r)?; Ok(ChannelId::from_bytes(buf)) } } +impl ToHex for ChannelId { + fn to_hex(&self) -> String { + self.data.to_hex() + } +} + +impl fmt::Display for ChannelId { + fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { + f.write_str(&self.to_hex()) + } +} /// Contains all state common to unfunded inbound/outbound channels. pub(super) struct UnfundedChannelContext { @@ -1315,7 +1325,8 @@ impl ChannelContext { log_trace!(logger, "Building commitment transaction number {} (really {} xor {}) for channel {} for {}, generated by {} with fee {}...", commitment_number, (INITIAL_COMMITMENT_NUMBER - commitment_number), get_commitment_transaction_number_obscure_factor(&self.get_holder_pubkeys().payment_point, &self.get_counterparty_pubkeys().payment_point, self.is_outbound()), - log_bytes!(self.channel_id.bytes()[..]), if local { "us" } else { "remote" }, if generated_by_local { "us" } else { "remote" }, feerate_per_kw); + &self.channel_id, + if local { "us" } else { "remote" }, if generated_by_local { "us" } else { "remote" }, feerate_per_kw); macro_rules! get_htlc_in_commitment { ($htlc: expr, $offered: expr) => { @@ -2311,7 +2322,7 @@ impl Channel { InboundHTLCState::LocalRemoved(ref reason) => { if let &InboundHTLCRemovalReason::Fulfill(_) = reason { } else { - log_warn!(logger, "Have preimage and want to fulfill HTLC with payment hash {} we already failed against channel {}", log_bytes!(htlc.payment_hash.0), log_bytes!(self.context.channel_id().bytes()[..])); + log_warn!(logger, "Have preimage and want to fulfill HTLC with payment hash {} we already failed against channel {}", log_bytes!(htlc.payment_hash.0), &self.context.channel_id()); debug_assert!(false, "Tried to fulfill an HTLC that was already failed"); } return UpdateFulfillFetch::DuplicateClaim {}; @@ -2364,7 +2375,7 @@ impl Channel { }, &HTLCUpdateAwaitingACK::FailHTLC { htlc_id, .. } => { if htlc_id_arg == htlc_id { - log_warn!(logger, "Have preimage and want to fulfill HTLC with pending failure against channel {}", log_bytes!(self.context.channel_id().bytes()[..])); + log_warn!(logger, "Have preimage and want to fulfill HTLC with pending failure against channel {}", &self.context.channel_id()); // TODO: We may actually be able to switch to a fulfill here, though its // rare enough it may not be worth the complexity burden. debug_assert!(false, "Tried to fulfill an HTLC that was already failed"); @@ -2374,7 +2385,7 @@ impl Channel { _ => {} } } - log_trace!(logger, "Adding HTLC claim to holding_cell in channel {}! Current state: {}", log_bytes!(self.context.channel_id().bytes()[..]), self.context.channel_state); + log_trace!(logger, "Adding HTLC claim to holding_cell in channel {}! Current state: {}", &self.context.channel_id(), self.context.channel_state); self.context.holding_cell_htlc_updates.push(HTLCUpdateAwaitingACK::ClaimHTLC { payment_preimage: payment_preimage_arg, htlc_id: htlc_id_arg, }); @@ -2392,7 +2403,7 @@ impl Channel { debug_assert!(false, "Have an inbound HTLC we tried to claim before it was fully committed to"); return UpdateFulfillFetch::NewClaim { monitor_update, htlc_value_msat, msg: None }; } - log_trace!(logger, "Upgrading HTLC {} to LocalRemoved with a Fulfill in channel {}!", log_bytes!(htlc.payment_hash.0), log_bytes!(self.context.channel_id.bytes()[..])); + log_trace!(logger, "Upgrading HTLC {} to LocalRemoved with a Fulfill in channel {}!", log_bytes!(htlc.payment_hash.0), &self.context.channel_id); htlc.state = InboundHTLCState::LocalRemoved(InboundHTLCRemovalReason::Fulfill(payment_preimage_arg.clone())); } @@ -2531,7 +2542,7 @@ impl Channel { _ => {} } } - log_trace!(logger, "Placing failure for HTLC ID {} in holding cell in channel {}.", htlc_id_arg, log_bytes!(self.context.channel_id().bytes()[..])); + log_trace!(logger, "Placing failure for HTLC ID {} in holding cell in channel {}.", htlc_id_arg, &self.context.channel_id()); self.context.holding_cell_htlc_updates.push(HTLCUpdateAwaitingACK::FailHTLC { htlc_id: htlc_id_arg, err_packet, @@ -2539,7 +2550,7 @@ impl Channel { return Ok(None); } - log_trace!(logger, "Failing HTLC ID {} back with a update_fail_htlc message in channel {}.", htlc_id_arg, log_bytes!(self.context.channel_id().bytes()[..])); + log_trace!(logger, "Failing HTLC ID {} back with a update_fail_htlc message in channel {}.", htlc_id_arg, &self.context.channel_id()); { let htlc = &mut self.context.pending_inbound_htlcs[pending_idx]; htlc.state = InboundHTLCState::LocalRemoved(InboundHTLCRemovalReason::FailRelay(err_packet.clone())); @@ -2583,7 +2594,7 @@ impl Channel { let counterparty_initial_bitcoin_tx = counterparty_trusted_tx.built_transaction(); log_trace!(logger, "Initial counterparty tx for channel {} is: txid {} tx {}", - log_bytes!(self.context.channel_id().bytes()[..]), counterparty_initial_bitcoin_tx.txid, encode::serialize_hex(&counterparty_initial_bitcoin_tx.transaction)); + &self.context.channel_id(), counterparty_initial_bitcoin_tx.txid, encode::serialize_hex(&counterparty_initial_bitcoin_tx.transaction)); let holder_signer = self.context.build_holder_transaction_keys(self.context.cur_holder_commitment_transaction_number); let initial_commitment_tx = self.context.build_commitment_transaction(self.context.cur_holder_commitment_transaction_number, &holder_signer, true, false, logger).tx; @@ -2631,7 +2642,7 @@ impl Channel { self.context.cur_holder_commitment_transaction_number -= 1; self.context.cur_counterparty_commitment_transaction_number -= 1; - log_info!(logger, "Received funding_signed from peer for channel {}", log_bytes!(self.context.channel_id().bytes()[..])); + log_info!(logger, "Received funding_signed from peer for channel {}", &self.context.channel_id()); let need_channel_ready = self.check_get_channel_ready(0).is_some(); self.monitor_updating_paused(false, false, need_channel_ready, Vec::new(), Vec::new(), Vec::new()); @@ -2705,7 +2716,7 @@ impl Channel { self.context.counterparty_prev_commitment_point = self.context.counterparty_cur_commitment_point; self.context.counterparty_cur_commitment_point = Some(msg.next_per_commitment_point); - log_info!(logger, "Received channel_ready from peer for channel {}", log_bytes!(self.context.channel_id().bytes()[..])); + log_info!(logger, "Received channel_ready from peer for channel {}", &self.context.channel_id()); Ok(self.get_announcement_sigs(node_signer, genesis_block_hash, user_config, best_block.height(), logger)) } @@ -2833,7 +2844,7 @@ impl Channel { if pending_remote_value_msat - msg.amount_msat - self.context.holder_selected_channel_reserve_satoshis * 1000 < remote_fee_cost_incl_stuck_buffer_msat { // Note that if the pending_forward_status is not updated here, then it's because we're already failing // the HTLC, i.e. its status is already set to failing. - log_info!(logger, "Attempting to fail HTLC due to fee spike buffer violation in channel {}. Rebalancing is required.", log_bytes!(self.context.channel_id().bytes()[..])); + log_info!(logger, "Attempting to fail HTLC due to fee spike buffer violation in channel {}. Rebalancing is required.", &self.context.channel_id()); pending_forward_status = create_pending_htlc_status(self, pending_forward_status, 0x1000|7); } } else { @@ -2961,7 +2972,7 @@ impl Channel { log_trace!(logger, "Checking commitment tx signature {} by key {} against tx {} (sighash {}) with redeemscript {} in channel {}", log_bytes!(msg.signature.serialize_compact()[..]), log_bytes!(self.context.counterparty_funding_pubkey().serialize()), encode::serialize_hex(&bitcoin_tx.transaction), - log_bytes!(sighash[..]), encode::serialize_hex(&funding_script), log_bytes!(self.context.channel_id().bytes()[..])); + log_bytes!(sighash[..]), encode::serialize_hex(&funding_script), &self.context.channel_id()); if let Err(_) = self.context.secp_ctx.verify_ecdsa(&sighash, &msg.signature, &self.context.counterparty_funding_pubkey()) { return Err(ChannelError::Close("Invalid commitment tx signature from peer".to_owned())); } @@ -3031,7 +3042,7 @@ impl Channel { let htlc_sighash = hash_to_message!(&sighash::SighashCache::new(&htlc_tx).segwit_signature_hash(0, &htlc_redeemscript, htlc.amount_msat / 1000, htlc_sighashtype).unwrap()[..]); log_trace!(logger, "Checking HTLC tx signature {} by key {} against tx {} (sighash {}) with redeemscript {} in channel {}.", log_bytes!(msg.htlc_signatures[idx].serialize_compact()[..]), log_bytes!(keys.countersignatory_htlc_key.serialize()), - encode::serialize_hex(&htlc_tx), log_bytes!(htlc_sighash[..]), encode::serialize_hex(&htlc_redeemscript), log_bytes!(self.context.channel_id().bytes()[..])); + encode::serialize_hex(&htlc_tx), log_bytes!(htlc_sighash[..]), encode::serialize_hex(&htlc_redeemscript), &self.context.channel_id()); if let Err(_) = self.context.secp_ctx.verify_ecdsa(&htlc_sighash, &msg.htlc_signatures[idx], &keys.countersignatory_htlc_key) { return Err(ChannelError::Close("Invalid HTLC tx signature from peer".to_owned())); } @@ -3075,7 +3086,7 @@ impl Channel { } else { None }; if let Some(forward_info) = new_forward { log_trace!(logger, "Updating HTLC {} to AwaitingRemoteRevokeToAnnounce due to commitment_signed in channel {}.", - log_bytes!(htlc.payment_hash.0), log_bytes!(self.context.channel_id.bytes()[..])); + log_bytes!(htlc.payment_hash.0), &self.context.channel_id); htlc.state = InboundHTLCState::AwaitingRemoteRevokeToAnnounce(forward_info); need_commitment = true; } @@ -3084,7 +3095,7 @@ impl Channel { for htlc in self.context.pending_outbound_htlcs.iter_mut() { if let &mut OutboundHTLCState::RemoteRemoved(ref mut outcome) = &mut htlc.state { log_trace!(logger, "Updating HTLC {} to AwaitingRemoteRevokeToRemove due to commitment_signed in channel {}.", - log_bytes!(htlc.payment_hash.0), log_bytes!(self.context.channel_id.bytes()[..])); + log_bytes!(htlc.payment_hash.0), &self.context.channel_id); // Grab the preimage, if it exists, instead of cloning let mut reason = OutboundHTLCOutcome::Success(None); mem::swap(outcome, &mut reason); @@ -3134,7 +3145,7 @@ impl Channel { monitor_update.updates.append(&mut additional_update.updates); } log_debug!(logger, "Received valid commitment_signed from peer in channel {}, updated HTLC state but awaiting a monitor update resolution to reply.", - log_bytes!(self.context.channel_id.bytes()[..])); + &self.context.channel_id); return Ok(self.push_ret_blockable_mon_update(monitor_update)); } @@ -3151,7 +3162,7 @@ impl Channel { } else { false }; log_debug!(logger, "Received valid commitment_signed from peer in channel {}, updating HTLC state and responding with{} a revoke_and_ack.", - log_bytes!(self.context.channel_id().bytes()[..]), if need_commitment_signed { " our own commitment_signed and" } else { "" }); + &self.context.channel_id(), if need_commitment_signed { " our own commitment_signed and" } else { "" }); self.monitor_updating_paused(true, need_commitment_signed, false, Vec::new(), Vec::new(), Vec::new()); return Ok(self.push_ret_blockable_mon_update(monitor_update)); } @@ -3180,7 +3191,7 @@ impl Channel { assert_eq!(self.context.channel_state & ChannelState::MonitorUpdateInProgress as u32, 0); if self.context.holding_cell_htlc_updates.len() != 0 || self.context.holding_cell_update_fee.is_some() { log_trace!(logger, "Freeing holding cell with {} HTLC updates{} in channel {}", self.context.holding_cell_htlc_updates.len(), - if self.context.holding_cell_update_fee.is_some() { " and a fee update" } else { "" }, log_bytes!(self.context.channel_id().bytes()[..])); + if self.context.holding_cell_update_fee.is_some() { " and a fee update" } else { "" }, &self.context.channel_id()); let mut monitor_update = ChannelMonitorUpdate { update_id: self.context.latest_monitor_update_id + 1, // We don't increment this yet! @@ -3212,7 +3223,7 @@ impl Channel { match e { ChannelError::Ignore(ref msg) => { log_info!(logger, "Failed to send HTLC with payment_hash {} due to {} in channel {}", - log_bytes!(payment_hash.0), msg, log_bytes!(self.context.channel_id().bytes()[..])); + log_bytes!(payment_hash.0), msg, &self.context.channel_id()); // If we fail to send here, then this HTLC should // be failed backwards. Failing to send here // indicates that this HTLC may keep being put back @@ -3278,7 +3289,7 @@ impl Channel { monitor_update.updates.append(&mut additional_update.updates); log_debug!(logger, "Freeing holding cell in channel {} resulted in {}{} HTLCs added, {} HTLCs fulfilled, and {} HTLCs failed.", - log_bytes!(self.context.channel_id().bytes()[..]), if update_fee.is_some() { "a fee update, " } else { "" }, + &self.context.channel_id(), if update_fee.is_some() { "a fee update, " } else { "" }, update_add_count, update_fulfill_count, update_fail_count); self.monitor_updating_paused(false, true, false, Vec::new(), Vec::new(), Vec::new()); @@ -3363,7 +3374,7 @@ impl Channel { self.context.announcement_sigs_state = AnnouncementSigsState::PeerReceived; } - log_trace!(logger, "Updating HTLCs on receipt of RAA in channel {}...", log_bytes!(self.context.channel_id().bytes()[..])); + log_trace!(logger, "Updating HTLCs on receipt of RAA in channel {}...", &self.context.channel_id()); let mut to_forward_infos = Vec::new(); let mut revoked_htlcs = Vec::new(); let mut finalized_claimed_htlcs = Vec::new(); @@ -3492,7 +3503,7 @@ impl Channel { self.context.monitor_pending_forwards.append(&mut to_forward_infos); self.context.monitor_pending_failures.append(&mut revoked_htlcs); self.context.monitor_pending_finalized_fulfills.append(&mut finalized_claimed_htlcs); - log_debug!(logger, "Received a valid revoke_and_ack for channel {} but awaiting a monitor update resolution to reply.", log_bytes!(self.context.channel_id().bytes()[..])); + log_debug!(logger, "Received a valid revoke_and_ack for channel {} but awaiting a monitor update resolution to reply.", &self.context.channel_id()); return Ok((Vec::new(), self.push_ret_blockable_mon_update(monitor_update))); } @@ -3516,11 +3527,11 @@ impl Channel { monitor_update.updates.append(&mut additional_update.updates); log_debug!(logger, "Received a valid revoke_and_ack for channel {}. Responding with a commitment update with {} HTLCs failed.", - log_bytes!(self.context.channel_id().bytes()[..]), update_fail_htlcs.len() + update_fail_malformed_htlcs.len()); + &self.context.channel_id(), update_fail_htlcs.len() + update_fail_malformed_htlcs.len()); self.monitor_updating_paused(false, true, false, to_forward_infos, revoked_htlcs, finalized_claimed_htlcs); Ok((htlcs_to_fail, self.push_ret_blockable_mon_update(monitor_update))) } else { - log_debug!(logger, "Received a valid revoke_and_ack for channel {} with no reply necessary.", log_bytes!(self.context.channel_id().bytes()[..])); + log_debug!(logger, "Received a valid revoke_and_ack for channel {} with no reply necessary.", &self.context.channel_id()); self.monitor_updating_paused(false, false, false, to_forward_infos, revoked_htlcs, finalized_claimed_htlcs); Ok((htlcs_to_fail, self.push_ret_blockable_mon_update(monitor_update))) } @@ -3681,7 +3692,7 @@ impl Channel { self.context.sent_message_awaiting_response = None; self.context.channel_state |= ChannelState::PeerDisconnected as u32; - log_trace!(logger, "Peer disconnection resulted in {} remote-announced HTLC drops on channel {}", inbound_drop_count, log_bytes!(self.context.channel_id().bytes()[..])); + log_trace!(logger, "Peer disconnection resulted in {} remote-announced HTLC drops on channel {}", inbound_drop_count, &self.context.channel_id()); } /// Indicates that a ChannelMonitor update is in progress and has not yet been fully persisted. @@ -3784,7 +3795,7 @@ impl Channel { self.context.monitor_pending_commitment_signed = false; let order = self.context.resend_order.clone(); log_debug!(logger, "Restored monitor updating in channel {} resulting in {}{} commitment update and {} RAA, with {} first", - log_bytes!(self.context.channel_id().bytes()[..]), if funding_broadcastable.is_some() { "a funding broadcastable, " } else { "" }, + &self.context.channel_id(), if funding_broadcastable.is_some() { "a funding broadcastable, " } else { "" }, if commitment_update.is_some() { "a" } else { "no" }, if raa.is_some() { "an" } else { "no" }, match order { RAACommitmentOrder::CommitmentFirst => "commitment", RAACommitmentOrder::RevokeAndACKFirst => "RAA"}); MonitorRestoreUpdates { @@ -3896,7 +3907,7 @@ impl Channel { } else { None }; log_trace!(logger, "Regenerated latest commitment update in channel {} with{} {} update_adds, {} update_fulfills, {} update_fails, and {} update_fail_malformeds", - log_bytes!(self.context.channel_id().bytes()[..]), if update_fee.is_some() { " update_fee," } else { "" }, + &self.context.channel_id(), if update_fee.is_some() { " update_fee," } else { "" }, update_add_htlcs.len(), update_fulfill_htlcs.len(), update_fail_htlcs.len(), update_fail_malformed_htlcs.len()); msgs::CommitmentUpdate { update_add_htlcs, update_fulfill_htlcs, update_fail_htlcs, update_fail_malformed_htlcs, update_fee, @@ -3941,8 +3952,8 @@ impl Channel { if msg.next_remote_commitment_number > INITIAL_COMMITMENT_NUMBER - self.context.cur_holder_commitment_transaction_number { macro_rules! log_and_panic { ($err_msg: expr) => { - log_error!(logger, $err_msg, log_bytes!(self.context.channel_id.bytes()[..]), log_pubkey!(self.context.counterparty_node_id)); - panic!($err_msg, log_bytes!(self.context.channel_id.bytes()[..]), log_pubkey!(self.context.counterparty_node_id)); + log_error!(logger, $err_msg, &self.context.channel_id, log_pubkey!(self.context.counterparty_node_id)); + panic!($err_msg, &self.context.channel_id, log_pubkey!(self.context.counterparty_node_id)); } } log_and_panic!("We have fallen behind - we have received proof that if we broadcast our counterparty is going to claim all our funds.\n\ @@ -4047,9 +4058,9 @@ impl Channel { if msg.next_local_commitment_number == next_counterparty_commitment_number { if required_revoke.is_some() { - log_debug!(logger, "Reconnected channel {} with only lost outbound RAA", log_bytes!(self.context.channel_id().bytes()[..])); + log_debug!(logger, "Reconnected channel {} with only lost outbound RAA", &self.context.channel_id()); } else { - log_debug!(logger, "Reconnected channel {} with no loss", log_bytes!(self.context.channel_id().bytes()[..])); + log_debug!(logger, "Reconnected channel {} with no loss", &self.context.channel_id()); } Ok(ReestablishResponses { @@ -4060,9 +4071,9 @@ impl Channel { }) } else if msg.next_local_commitment_number == next_counterparty_commitment_number - 1 { if required_revoke.is_some() { - log_debug!(logger, "Reconnected channel {} with lost outbound RAA and lost remote commitment tx", log_bytes!(self.context.channel_id().bytes()[..])); + log_debug!(logger, "Reconnected channel {} with lost outbound RAA and lost remote commitment tx", &self.context.channel_id()); } else { - log_debug!(logger, "Reconnected channel {} with only lost remote commitment tx", log_bytes!(self.context.channel_id().bytes()[..])); + log_debug!(logger, "Reconnected channel {} with only lost remote commitment tx", &self.context.channel_id()); } if self.context.channel_state & (ChannelState::MonitorUpdateInProgress as u32) != 0 { @@ -4796,14 +4807,14 @@ impl Channel { // send it immediately instead of waiting for a best_block_updated call (which // may have already happened for this block). if let Some(channel_ready) = self.check_get_channel_ready(height) { - log_info!(logger, "Sending a channel_ready to our peer for channel {}", log_bytes!(self.context.channel_id.bytes()[..])); + log_info!(logger, "Sending a channel_ready to our peer for channel {}", &self.context.channel_id); let announcement_sigs = self.get_announcement_sigs(node_signer, genesis_block_hash, user_config, height, logger); return Ok((Some(channel_ready), announcement_sigs)); } } for inp in tx.input.iter() { if inp.previous_output == funding_txo.into_bitcoin_outpoint() { - log_info!(logger, "Detected channel-closing tx {} spending {}:{}, closing channel {}", tx.txid(), inp.previous_output.txid, inp.previous_output.vout, log_bytes!(self.context.channel_id().bytes()[..])); + log_info!(logger, "Detected channel-closing tx {} spending {}:{}, closing channel {}", tx.txid(), inp.previous_output.txid, inp.previous_output.vout, &self.context.channel_id()); return Err(ClosureReason::CommitmentTxConfirmed); } } @@ -4865,7 +4876,7 @@ impl Channel { let announcement_sigs = if let Some((genesis_block_hash, node_signer, user_config)) = genesis_node_signer { self.get_announcement_sigs(node_signer, genesis_block_hash, user_config, height, logger) } else { None }; - log_info!(logger, "Sending a channel_ready to our peer for channel {}", log_bytes!(self.context.channel_id.bytes()[..])); + log_info!(logger, "Sending a channel_ready to our peer for channel {}", &self.context.channel_id); return Ok((Some(channel_ready), timed_out_htlcs, announcement_sigs)); } @@ -4896,7 +4907,7 @@ impl Channel { } } else if !self.context.is_outbound() && self.context.funding_tx_confirmed_in.is_none() && height >= self.context.channel_creation_height + FUNDING_CONF_DEADLINE_BLOCKS { - log_info!(logger, "Closing channel {} due to funding timeout", log_bytes!(self.context.channel_id.bytes()[..])); + log_info!(logger, "Closing channel {} due to funding timeout", &self.context.channel_id); // If funding_tx_confirmed_in is unset, the channel must not be active assert!(non_shutdown_state <= ChannelState::ChannelReady as u32); assert_eq!(non_shutdown_state & ChannelState::OurChannelReady as u32, 0); @@ -5006,7 +5017,7 @@ impl Channel { return None; } - log_trace!(logger, "Creating an announcement_signatures message for channel {}", log_bytes!(self.context.channel_id().bytes()[..])); + log_trace!(logger, "Creating an announcement_signatures message for channel {}", &self.context.channel_id()); let announcement = match self.get_channel_announcement(node_signer, genesis_block_hash, user_config) { Ok(a) => a, Err(e) => { @@ -5133,10 +5144,10 @@ impl Channel { let dummy_pubkey = PublicKey::from_slice(&pk).unwrap(); let remote_last_secret = if self.context.cur_counterparty_commitment_transaction_number + 1 < INITIAL_COMMITMENT_NUMBER { let remote_last_secret = self.context.commitment_secrets.get_secret(self.context.cur_counterparty_commitment_transaction_number + 2).unwrap(); - log_trace!(logger, "Enough info to generate a Data Loss Protect with per_commitment_secret {} for channel {}", log_bytes!(remote_last_secret), log_bytes!(self.context.channel_id().bytes()[..])); + log_trace!(logger, "Enough info to generate a Data Loss Protect with per_commitment_secret {} for channel {}", log_bytes!(remote_last_secret), &self.context.channel_id()); remote_last_secret } else { - log_info!(logger, "Sending a data_loss_protect with no previous remote per_commitment_secret for channel {}", log_bytes!(self.context.channel_id().bytes()[..])); + log_info!(logger, "Sending a data_loss_protect with no previous remote per_commitment_secret for channel {}", &self.context.channel_id()); [0;32] }; self.mark_awaiting_response(); @@ -5405,14 +5416,14 @@ impl Channel { log_trace!(logger, "Signed remote commitment tx {} (txid {}) with redeemscript {} -> {} in channel {}", encode::serialize_hex(&commitment_stats.tx.trust().built_transaction().transaction), &counterparty_commitment_txid, encode::serialize_hex(&self.context.get_funding_redeemscript()), - log_bytes!(signature.serialize_compact()[..]), log_bytes!(self.context.channel_id().bytes()[..])); + log_bytes!(signature.serialize_compact()[..]), &self.context.channel_id()); for (ref htlc_sig, ref htlc) in htlc_signatures.iter().zip(htlcs) { log_trace!(logger, "Signed remote HTLC tx {} with redeemscript {} with pubkey {} -> {} in channel {}", encode::serialize_hex(&chan_utils::build_htlc_transaction(&counterparty_commitment_txid, commitment_stats.feerate_per_kw, self.context.get_holder_selected_contest_delay(), htlc, &self.context.channel_type, &counterparty_keys.broadcaster_delayed_payment_key, &counterparty_keys.revocation_key)), encode::serialize_hex(&chan_utils::get_htlc_redeemscript(&htlc, &self.context.channel_type, &counterparty_keys)), log_bytes!(counterparty_keys.broadcaster_htlc_key.serialize()), - log_bytes!(htlc_sig.serialize_compact()[..]), log_bytes!(self.context.channel_id().bytes()[..])); + log_bytes!(htlc_sig.serialize_compact()[..]), &self.context.channel_id()); } } @@ -6517,7 +6528,7 @@ impl InboundV1Channel { log_trace!(logger, "Checking funding_created tx signature {} by key {} against tx {} (sighash {}) with redeemscript {} for channel {}.", log_bytes!(sig.serialize_compact()[..]), log_bytes!(self.context.counterparty_funding_pubkey().serialize()), encode::serialize_hex(&initial_commitment_bitcoin_tx.transaction), log_bytes!(sighash[..]), - encode::serialize_hex(&funding_script), log_bytes!(self.context.channel_id().bytes()[..])); + encode::serialize_hex(&funding_script), &self.context.channel_id()); secp_check!(self.context.secp_ctx.verify_ecdsa(&sighash, &sig, self.context.counterparty_funding_pubkey()), "Invalid funding_created signature from peer".to_owned()); } @@ -6527,7 +6538,7 @@ impl InboundV1Channel { let counterparty_trusted_tx = counterparty_initial_commitment_tx.trust(); let counterparty_initial_bitcoin_tx = counterparty_trusted_tx.built_transaction(); log_trace!(logger, "Initial counterparty tx for channel {} is: txid {} tx {}", - log_bytes!(self.context.channel_id().bytes()[..]), counterparty_initial_bitcoin_tx.txid, encode::serialize_hex(&counterparty_initial_bitcoin_tx.transaction)); + &self.context.channel_id(), counterparty_initial_bitcoin_tx.txid, encode::serialize_hex(&counterparty_initial_bitcoin_tx.transaction)); let counterparty_signature = self.context.holder_signer.sign_counterparty_commitment(&counterparty_initial_commitment_tx, Vec::new(), &self.context.secp_ctx) .map_err(|_| ChannelError::Close("Failed to get signatures for new commitment_signed".to_owned()))?.0; @@ -6615,7 +6626,7 @@ impl InboundV1Channel { self.context.cur_counterparty_commitment_transaction_number -= 1; self.context.cur_holder_commitment_transaction_number -= 1; - log_info!(logger, "Generated funding_signed for peer for channel {}", log_bytes!(self.context.channel_id().bytes()[..])); + log_info!(logger, "Generated funding_signed for peer for channel {}", &self.context.channel_id()); // Promote the channel to a full-fledged one now that we have updated the state and have a // `ChannelMonitor`. @@ -7555,6 +7566,7 @@ mod tests { use bitcoin::hash_types::WPubkeyHash; use bitcoin::PackedLockTime; use bitcoin::util::address::WitnessVersion; + use bitcoin::hashes::hex::ToHex; use crate::prelude::*; use crate::io; @@ -7577,7 +7589,7 @@ mod tests { #[test] fn test_channel_id_from_funding_tx2() { let channel_id = ChannelId::from_funding_txid(&[2; 32], 1); - assert_eq!(hex::encode(channel_id.bytes()), "0202020202020202020202020202020202020202020202020202020202020203"); + assert_eq!(channel_id.to_hex(), "0202020202020202020202020202020202020202020202020202020202020203"); } #[test] diff --git a/lightning/src/ln/channelmanager.rs b/lightning/src/ln/channelmanager.rs index e0b74f9798d..c3753d98b5d 100644 --- a/lightning/src/ln/channelmanager.rs +++ b/lightning/src/ln/channelmanager.rs @@ -1768,7 +1768,7 @@ macro_rules! convert_chan_err { (false, MsgHandleErrInternal::from_chan_no_close(ChannelError::Ignore(msg), $channel_id.clone())) }, ChannelError::Close(msg) => { - log_error!($self.logger, "Closing channel {} due to close-required error: {}", log_bytes!($channel_id.bytes()[..][..]), msg); + log_error!($self.logger, "Closing channel {} due to close-required error: {}", &$channel_id, msg); update_maps_on_chan_removal!($self, &$channel.context); let shutdown_res = $channel.context.force_shutdown(true); (true, MsgHandleErrInternal::from_finish_shutdown(msg, *$channel_id, $channel.context.get_user_id(), @@ -1781,7 +1781,7 @@ macro_rules! convert_chan_err { // We should only ever have `ChannelError::Close` when unfunded channels error. // In any case, just close the channel. ChannelError::Warn(msg) | ChannelError::Ignore(msg) | ChannelError::Close(msg) => { - log_error!($self.logger, "Closing unfunded channel {} due to an error: {}", log_bytes!($channel_id.bytes()[..][..]), msg); + log_error!($self.logger, "Closing unfunded channel {} due to an error: {}", &$channel_id, msg); update_maps_on_chan_removal!($self, &$channel_context); let shutdown_res = $channel_context.force_shutdown(false); (true, MsgHandleErrInternal::from_finish_shutdown(msg, *$channel_id, $channel_context.get_user_id(), @@ -1954,12 +1954,12 @@ macro_rules! handle_new_monitor_update { match $update_res { ChannelMonitorUpdateStatus::InProgress => { log_debug!($self.logger, "ChannelMonitor update for {} in flight, holding messages until the update completes.", - log_bytes!($chan.context.channel_id().bytes()[..][..])); + &$chan.context.channel_id()); Ok(false) }, ChannelMonitorUpdateStatus::PermanentFailure => { log_error!($self.logger, "Closing channel {} due to monitor update ChannelMonitorUpdateStatus::PermanentFailure", - log_bytes!($chan.context.channel_id().bytes()[..][..])); + &$chan.context.channel_id()); update_maps_on_chan_removal!($self, &$chan.context); let res = Err(MsgHandleErrInternal::from_finish_shutdown( "ChannelMonitor storage failure".to_owned(), $chan.context.channel_id(), @@ -2569,27 +2569,27 @@ where ClosureReason::HolderForceClosed }; if let hash_map::Entry::Occupied(chan) = peer_state.channel_by_id.entry(channel_id.clone()) { - log_error!(self.logger, "Force-closing channel {}", log_bytes!(channel_id.bytes()[..][..])); + log_error!(self.logger, "Force-closing channel {}", &channel_id); self.issue_channel_close_events(&chan.get().context, closure_reason); let mut chan = remove_channel!(self, chan); self.finish_force_close_channel(chan.context.force_shutdown(broadcast)); (self.get_channel_update_for_broadcast(&chan).ok(), chan.context.get_counterparty_node_id()) } else if let hash_map::Entry::Occupied(chan) = peer_state.outbound_v1_channel_by_id.entry(channel_id.clone()) { - log_error!(self.logger, "Force-closing channel {}", log_bytes!(channel_id.bytes()[..][..])); + log_error!(self.logger, "Force-closing channel {}", &channel_id); self.issue_channel_close_events(&chan.get().context, closure_reason); let mut chan = remove_channel!(self, chan); self.finish_force_close_channel(chan.context.force_shutdown(false)); // Unfunded channel has no update (None, chan.context.get_counterparty_node_id()) } else if let hash_map::Entry::Occupied(chan) = peer_state.inbound_v1_channel_by_id.entry(channel_id.clone()) { - log_error!(self.logger, "Force-closing channel {}", log_bytes!(channel_id.bytes()[..][..])); + log_error!(self.logger, "Force-closing channel {}", &channel_id); self.issue_channel_close_events(&chan.get().context, closure_reason); let mut chan = remove_channel!(self, chan); self.finish_force_close_channel(chan.context.force_shutdown(false)); // Unfunded channel has no update (None, chan.context.get_counterparty_node_id()) } else { - return Err(APIError::ChannelUnavailable{ err: format!("Channel with id {} not found for the passed counterparty node_id {}", log_bytes!((*channel_id).bytes()[..]), peer_node_id) }); + return Err(APIError::ChannelUnavailable{ err: format!("Channel with id {} not found for the passed counterparty node_id {}", channel_id, peer_node_id) }); } }; if let Some(update) = update_opt { @@ -3079,7 +3079,7 @@ where if chan.context.get_short_channel_id().is_none() { return Err(LightningError{err: "Channel not yet established".to_owned(), action: msgs::ErrorAction::IgnoreError}); } - log_trace!(self.logger, "Attempting to generate broadcast channel update for channel {}", log_bytes!(chan.context.channel_id().bytes()[..])); + log_trace!(self.logger, "Attempting to generate broadcast channel update for channel {}", &chan.context.channel_id()); self.get_channel_update_for_unicast(chan) } @@ -3095,7 +3095,7 @@ where /// [`channel_update`]: msgs::ChannelUpdate /// [`internal_closing_signed`]: Self::internal_closing_signed fn get_channel_update_for_unicast(&self, chan: &Channel<::Signer>) -> Result { - log_trace!(self.logger, "Attempting to generate channel update for channel {}", log_bytes!(chan.context.channel_id().bytes()[..])); + log_trace!(self.logger, "Attempting to generate channel update for channel {}", &chan.context.channel_id()); let short_channel_id = match chan.context.get_short_channel_id().or(chan.context.latest_inbound_scid_alias()) { None => return Err(LightningError{err: "Channel not yet established".to_owned(), action: msgs::ErrorAction::IgnoreError}), Some(id) => id, @@ -3105,7 +3105,7 @@ where } fn get_channel_update_for_onion(&self, short_channel_id: u64, chan: &Channel<::Signer>) -> Result { - log_trace!(self.logger, "Generating channel update for channel {}", log_bytes!(chan.context.channel_id().bytes()[..])); + log_trace!(self.logger, "Generating channel update for channel {}", &chan.context.channel_id()); let were_node_one = self.our_network_pubkey.serialize()[..] < chan.context.get_counterparty_node_id().serialize()[..]; let enabled = chan.context.is_usable() && match chan.channel_update_status() { @@ -3436,7 +3436,7 @@ where return Err(APIError::ChannelUnavailable { err: format!( "Channel with id {} not found for the passed counterparty node_id {}", - log_bytes!((*temporary_channel_id).bytes()[..]), counterparty_node_id), + temporary_channel_id, counterparty_node_id), }) }, }; @@ -3587,7 +3587,7 @@ where for channel_id in channel_ids { if !peer_state.has_channel(channel_id) { return Err(APIError::ChannelUnavailable { - err: format!("Channel with ID {} was not found for the passed counterparty_node_id {}", log_bytes!((*channel_id).bytes()[..]), counterparty_node_id), + err: format!("Channel with ID {} was not found for the passed counterparty_node_id {}", channel_id, counterparty_node_id), }); }; } @@ -3619,7 +3619,7 @@ where return Err(APIError::ChannelUnavailable { err: format!( "Channel with ID {} for passed counterparty_node_id {} disappeared after we confirmed its existence - this should not be reachable!", - log_bytes!((*channel_id).bytes()[..]), counterparty_node_id), + channel_id, counterparty_node_id), }); }; let mut config = context.config(); @@ -3697,14 +3697,14 @@ where Some(chan) => { if !chan.context.is_usable() { return Err(APIError::ChannelUnavailable { - err: format!("Channel with id {} not fully established", log_bytes!((*next_hop_channel_id).bytes()[..])) + err: format!("Channel with id {} not fully established", next_hop_channel_id) }) } chan.context.get_short_channel_id().unwrap_or(chan.context.outbound_scid_alias()) }, None => return Err(APIError::ChannelUnavailable { err: format!("Funded channel with id {} not found for the passed counterparty node_id {}. Channel may still be opening.", - log_bytes!((*next_hop_channel_id).bytes()[..]), next_node_id) + next_hop_channel_id, next_node_id) }) } }; @@ -4316,16 +4316,16 @@ where // If the feerate has decreased by less than half, don't bother if new_feerate <= chan.context.get_feerate_sat_per_1000_weight() && new_feerate * 2 > chan.context.get_feerate_sat_per_1000_weight() { log_trace!(self.logger, "Channel {} does not qualify for a feerate change from {} to {}.", - log_bytes!(chan_id.bytes()[..]), chan.context.get_feerate_sat_per_1000_weight(), new_feerate); + &chan_id, chan.context.get_feerate_sat_per_1000_weight(), new_feerate); return NotifyOption::SkipPersist; } if !chan.context.is_live() { log_trace!(self.logger, "Channel {} does not qualify for a feerate change from {} to {} as it cannot currently be updated (probably the peer is disconnected).", - log_bytes!(chan_id.bytes()[..]), chan.context.get_feerate_sat_per_1000_weight(), new_feerate); + &chan_id, chan.context.get_feerate_sat_per_1000_weight(), new_feerate); return NotifyOption::SkipPersist; } log_trace!(self.logger, "Channel {} qualifies for a feerate change from {} to {}.", - log_bytes!(chan_id.bytes()[..]), chan.context.get_feerate_sat_per_1000_weight(), new_feerate); + &chan_id, chan.context.get_feerate_sat_per_1000_weight(), new_feerate); chan.queue_update_fee(new_feerate, &self.fee_estimator, &self.logger); NotifyOption::DoPersist @@ -4453,7 +4453,7 @@ where if chan.should_disconnect_peer_awaiting_response() { log_debug!(self.logger, "Disconnecting peer {} due to not making any progress on channel {}", - counterparty_node_id, log_bytes!((*chan_id).bytes()[..])); + counterparty_node_id, chan_id); pending_msg_events.push(MessageSendEvent::HandleError { node_id: counterparty_node_id, action: msgs::ErrorAction::DisconnectPeerWithWarning { @@ -4475,7 +4475,7 @@ where | { chan_context.maybe_expire_prev_config(); if unfunded_chan_context.should_expire_unfunded_channel() { - log_error!(self.logger, "Force-closing pending outbound channel {} for not establishing in a timely manner", log_bytes!(&chan_id.bytes()[..])); + log_error!(self.logger, "Force-closing pending outbound channel {} for not establishing in a timely manner", &chan_id); update_maps_on_chan_removal!(self, &chan_context); self.issue_channel_close_events(&chan_context, ClosureReason::HolderForceClosed); self.finish_force_close_channel(chan_context.force_shutdown(false)); @@ -4951,7 +4951,7 @@ where if let UpdateFulfillCommitFetch::NewClaim { htlc_value_msat, monitor_update } = fulfill_res { if let Some(action) = completion_action(Some(htlc_value_msat)) { log_trace!(self.logger, "Tracking monitor update completion action for channel {}: {:?}", - log_bytes!(chan_id.bytes()[..]), action); + &chan_id, action); peer_state.monitor_update_blocked_actions.entry(chan_id).or_insert(Vec::new()).push(action); } if !during_init { @@ -5101,7 +5101,7 @@ where channel_ready: Option, announcement_sigs: Option) -> Option<(u64, OutPoint, u128, Vec<(PendingHTLCInfo, u64)>)> { log_trace!(self.logger, "Handling channel resumption for channel {} with {} RAA, {} commitment update, {} pending forwards, {}broadcasting funding, {} channel ready, {} announcement", - log_bytes!(channel.context.channel_id().bytes()[..]), + &channel.context.channel_id(), if raa.is_some() { "an" } else { "no" }, if commitment_update.is_some() { "a" } else { "no" }, pending_forwards.len(), if funding_broadcastable.is_some() { "" } else { "not " }, @@ -5306,7 +5306,7 @@ where }); } hash_map::Entry::Vacant(_) => { - return Err(APIError::ChannelUnavailable { err: format!("Channel with id {} not found for the passed counterparty node_id {}", log_bytes!((*temporary_channel_id).bytes()[..]), counterparty_node_id) }); + return Err(APIError::ChannelUnavailable { err: format!("Channel with id {} not found for the passed counterparty node_id {}", temporary_channel_id, counterparty_node_id) }); } } Ok(()) @@ -5601,7 +5601,7 @@ where let announcement_sigs_opt = try_chan_entry!(self, chan.get_mut().channel_ready(&msg, &self.node_signer, self.genesis_hash.clone(), &self.default_configuration, &self.best_block.read().unwrap(), &self.logger), chan); if let Some(announcement_sigs) = announcement_sigs_opt { - log_trace!(self.logger, "Sending announcement_signatures for channel {}", log_bytes!(chan.get().context.channel_id().bytes()[..])); + log_trace!(self.logger, "Sending announcement_signatures for channel {}", &chan.get().context.channel_id()); peer_state.pending_msg_events.push(events::MessageSendEvent::SendAnnouncementSignatures { node_id: counterparty_node_id.clone(), msg: announcement_sigs, @@ -5612,7 +5612,7 @@ where // counterparty's announcement_signatures. Thus, we only bother to send a // channel_update here if the channel is not public, i.e. we're not sending an // announcement_signatures. - log_trace!(self.logger, "Sending private initial channel_update for our counterparty on channel {}", log_bytes!(chan.get().context.channel_id().bytes()[..])); + log_trace!(self.logger, "Sending private initial channel_update for our counterparty on channel {}", &chan.get().context.channel_id()); if let Ok(msg) = self.get_channel_update_for_unicast(chan.get()) { peer_state.pending_msg_events.push(events::MessageSendEvent::SendChannelUpdate { node_id: counterparty_node_id.clone(), @@ -5646,13 +5646,13 @@ where // TODO(dunxen): Fix this duplication when we switch to a single map with enums as per // https://github.com/lightningdevkit/rust-lightning/issues/2422 if let hash_map::Entry::Occupied(chan_entry) = peer_state.outbound_v1_channel_by_id.entry(msg.channel_id.clone()) { - log_error!(self.logger, "Immediately closing unfunded channel {} as peer asked to cooperatively shut it down (which is unnecessary)", log_bytes!(&msg.channel_id.bytes()[..][..])); + log_error!(self.logger, "Immediately closing unfunded channel {} as peer asked to cooperatively shut it down (which is unnecessary)", &msg.channel_id); self.issue_channel_close_events(&chan_entry.get().context, ClosureReason::CounterpartyCoopClosedUnfundedChannel); let mut chan = remove_channel!(self, chan_entry); self.finish_force_close_channel(chan.context.force_shutdown(false)); return Ok(()); } else if let hash_map::Entry::Occupied(chan_entry) = peer_state.inbound_v1_channel_by_id.entry(msg.channel_id.clone()) { - log_error!(self.logger, "Immediately closing unfunded channel {} as peer asked to cooperatively shut it down (which is unnecessary)", log_bytes!(&msg.channel_id.bytes()[..][..])); + log_error!(self.logger, "Immediately closing unfunded channel {} as peer asked to cooperatively shut it down (which is unnecessary)", &msg.channel_id); self.issue_channel_close_events(&chan_entry.get().context, ClosureReason::CounterpartyCoopClosedUnfundedChannel); let mut chan = remove_channel!(self, chan_entry); self.finish_force_close_channel(chan.context.force_shutdown(false)); @@ -5660,7 +5660,7 @@ where } else if let hash_map::Entry::Occupied(mut chan_entry) = peer_state.channel_by_id.entry(msg.channel_id.clone()) { if !chan_entry.get().received_shutdown() { log_info!(self.logger, "Received a shutdown message from our counterparty for channel {}{}.", - log_bytes!(msg.channel_id.bytes()[..]), + &msg.channel_id, if chan_entry.get().sent_shutdown() { " after we initiated shutdown" } else { "" }); } @@ -6112,7 +6112,7 @@ where if were_node_one == msg_from_node_one { return Ok(NotifyOption::SkipPersist); } else { - log_debug!(self.logger, "Received channel_update for channel {}.", log_bytes!(chan_id.bytes()[..])); + log_debug!(self.logger, "Received channel_update for channel {}.", &chan_id); try_chan_entry!(self, chan.get_mut().channel_update(&msg), chan); } }, @@ -6630,7 +6630,7 @@ where // blocking monitor updates for this channel. If we do, release the monitor // update(s) when those blockers complete. log_trace!(self.logger, "Delaying monitor unlock for channel {} as another channel's mon update needs to complete first", - log_bytes!(&channel_funding_outpoint.to_channel_id().bytes()[..][..])); + &channel_funding_outpoint.to_channel_id()); break; } @@ -6638,7 +6638,7 @@ where debug_assert_eq!(chan.get().context.get_funding_txo().unwrap(), channel_funding_outpoint); if let Some((monitor_update, further_update_exists)) = chan.get_mut().unblock_next_blocked_monitor_update() { log_debug!(self.logger, "Unlocking monitor updating for channel {} and updating monitor", - log_bytes!(&channel_funding_outpoint.to_channel_id().bytes()[..][..])); + &channel_funding_outpoint.to_channel_id()); if let Err(e) = handle_new_monitor_update!(self, channel_funding_outpoint, monitor_update, peer_state_lck, peer_state, per_peer_state, chan) { @@ -6651,7 +6651,7 @@ where } } else { log_trace!(self.logger, "Unlocked monitor updating for channel {} without monitors to update", - log_bytes!(&channel_funding_outpoint.to_channel_id().bytes()[..][..])); + &channel_funding_outpoint.to_channel_id()); } } } else { @@ -6949,7 +6949,7 @@ where if let Some(channel_ready) = channel_ready_opt { send_channel_ready!(self, pending_msg_events, channel, channel_ready); if channel.context.is_usable() { - log_trace!(self.logger, "Sending channel_ready with private initial channel_update for our counterparty on channel {}", log_bytes!(channel.context.channel_id().bytes()[..])); + log_trace!(self.logger, "Sending channel_ready with private initial channel_update for our counterparty on channel {}", &channel.context.channel_id()); if let Ok(msg) = self.get_channel_update_for_unicast(channel) { pending_msg_events.push(events::MessageSendEvent::SendChannelUpdate { node_id: channel.context.get_counterparty_node_id(), @@ -6957,7 +6957,7 @@ where }); } } else { - log_trace!(self.logger, "Sending channel_ready WITHOUT channel_update for {}", log_bytes!(channel.context.channel_id().bytes()[..])); + log_trace!(self.logger, "Sending channel_ready WITHOUT channel_update for {}", &channel.context.channel_id()); } } @@ -6967,7 +6967,7 @@ where } if let Some(announcement_sigs) = announcement_sigs { - log_trace!(self.logger, "Sending announcement_signatures for channel {}", log_bytes!(channel.context.channel_id().bytes()[..])); + log_trace!(self.logger, "Sending announcement_signatures for channel {}", &channel.context.channel_id()); pending_msg_events.push(events::MessageSendEvent::SendAnnouncementSignatures { node_id: channel.context.get_counterparty_node_id(), msg: announcement_sigs, @@ -8440,7 +8440,7 @@ where log_error!(args.logger, "A ChannelManager is stale compared to the current ChannelMonitor!"); log_error!(args.logger, " The channel will be force-closed and the latest commitment transaction from the ChannelMonitor broadcast."); log_error!(args.logger, " The ChannelMonitor for channel {} is at update_id {} but the ChannelManager is at update_id {}.", - log_bytes!(channel.context.channel_id().bytes()[..]), monitor.get_latest_update_id(), channel.context.get_latest_monitor_update_id()); + &channel.context.channel_id(), monitor.get_latest_update_id(), channel.context.get_latest_monitor_update_id()); let (monitor_update, mut new_failed_htlcs) = channel.context.force_shutdown(true); if let Some((counterparty_node_id, funding_txo, update)) = monitor_update { close_background_events.push(BackgroundEvent::MonitorUpdateRegeneratedOnStartup { @@ -8470,13 +8470,13 @@ where // backwards leg of the HTLC will simply be rejected. log_info!(args.logger, "Failing HTLC with hash {} as it is missing in the ChannelMonitor for channel {} but was present in the (stale) ChannelManager", - log_bytes!(channel.context.channel_id().bytes()[..]), log_bytes!(payment_hash.0)); + &channel.context.channel_id(), log_bytes!(payment_hash.0)); failed_htlcs.push((channel_htlc_source.clone(), *payment_hash, channel.context.get_counterparty_node_id(), channel.context.channel_id())); } } } else { log_info!(args.logger, "Successfully loaded channel {} at update_id {} against monitor at update id {}", - log_bytes!(channel.context.channel_id().bytes()[..]), channel.context.get_latest_monitor_update_id(), + &channel.context.channel_id(), channel.context.get_latest_monitor_update_id(), monitor.get_latest_update_id()); if let Some(short_channel_id) = channel.context.get_short_channel_id() { short_to_chan_info.insert(short_channel_id, (channel.context.get_counterparty_node_id(), channel.context.channel_id())); @@ -8509,7 +8509,7 @@ where channel_capacity_sats: Some(channel.context.get_value_satoshis()), }, None)); } else { - log_error!(args.logger, "Missing ChannelMonitor for channel {} needed by ChannelManager.", log_bytes!(channel.context.channel_id().bytes()[..])); + log_error!(args.logger, "Missing ChannelMonitor for channel {} needed by ChannelManager.", &channel.context.channel_id()); log_error!(args.logger, " The chain::Watch API *requires* that monitors are persisted durably before returning,"); log_error!(args.logger, " client applications must ensure that ChannelMonitor data is always available and the latest to avoid funds loss!"); log_error!(args.logger, " Without the ChannelMonitor we cannot continue without risking funds."); @@ -8521,7 +8521,7 @@ where for (funding_txo, _) in args.channel_monitors.iter() { if !funding_txo_set.contains(funding_txo) { log_info!(args.logger, "Queueing monitor update to ensure missing channel {} is force closed", - log_bytes!(funding_txo.to_channel_id().bytes()[..])); + &funding_txo.to_channel_id()); let monitor_update = ChannelMonitorUpdate { update_id: CLOSED_CHANNEL_UPDATE_ID, updates: vec![ChannelMonitorUpdateStep::ChannelForceClosed { should_broadcast: true }], @@ -8704,7 +8704,7 @@ where $chan_in_flight_upds.retain(|upd| upd.update_id > $monitor.get_latest_update_id()); for update in $chan_in_flight_upds.iter() { log_trace!(args.logger, "Replaying ChannelMonitorUpdate {} for {}channel {}", - update.update_id, $channel_info_log, log_bytes!($funding_txo.to_channel_id().bytes()[..])); + update.update_id, $channel_info_log, &$funding_txo.to_channel_id()); max_in_flight_update_id = cmp::max(max_in_flight_update_id, update.update_id); pending_background_events.push( BackgroundEvent::MonitorUpdateRegeneratedOnStartup { @@ -8752,7 +8752,7 @@ where // If the channel is ahead of the monitor, return InvalidValue: log_error!(args.logger, "A ChannelMonitor is stale compared to the current ChannelManager! This indicates a potentially-critical violation of the chain::Watch API!"); log_error!(args.logger, " The ChannelMonitor for channel {} is at update_id {} with update_id through {} in-flight", - log_bytes!(chan.context.channel_id().bytes()[..]), monitor.get_latest_update_id(), max_in_flight_update_id); + &chan.context.channel_id(), monitor.get_latest_update_id(), max_in_flight_update_id); log_error!(args.logger, " but the ChannelManager is at update_id {}.", chan.get_latest_unblocked_monitor_update_id()); log_error!(args.logger, " The chain::Watch API *requires* that monitors are persisted durably before returning,"); log_error!(args.logger, " client applications must ensure that ChannelMonitor data is always available and the latest to avoid funds loss!"); @@ -8778,7 +8778,7 @@ where } else { log_error!(args.logger, "A ChannelMonitor is missing even though we have in-flight updates for it! This indicates a potentially-critical violation of the chain::Watch API!"); log_error!(args.logger, " The ChannelMonitor for channel {} is missing.", - log_bytes!(funding_txo.to_channel_id().bytes()[..])); + &funding_txo.to_channel_id()); log_error!(args.logger, " The chain::Watch API *requires* that monitors are persisted durably before returning,"); log_error!(args.logger, " client applications must ensure that ChannelMonitor data is always available and the latest to avoid funds loss!"); log_error!(args.logger, " Without the latest ChannelMonitor we cannot continue without risking funds."); @@ -8864,7 +8864,7 @@ where if let HTLCForwardInfo::AddHTLC(htlc_info) = forward { if pending_forward_matches_htlc(&htlc_info) { log_info!(args.logger, "Removing pending to-forward HTLC with hash {} as it was forwarded to the closed channel {}", - log_bytes!(htlc.payment_hash.0), log_bytes!(monitor.get_funding_txo().0.to_channel_id().bytes()[..])); + log_bytes!(htlc.payment_hash.0), &monitor.get_funding_txo().0.to_channel_id()); false } else { true } } else { true } @@ -8874,7 +8874,7 @@ where pending_intercepted_htlcs.as_mut().unwrap().retain(|intercepted_id, htlc_info| { if pending_forward_matches_htlc(&htlc_info) { log_info!(args.logger, "Removing pending intercepted HTLC with hash {} as it was forwarded to the closed channel {}", - log_bytes!(htlc.payment_hash.0), log_bytes!(monitor.get_funding_txo().0.to_channel_id().bytes()[..])); + log_bytes!(htlc.payment_hash.0), &monitor.get_funding_txo().0.to_channel_id()); pending_events_read.retain(|(event, _)| { if let Event::HTLCIntercepted { intercept_id: ev_id, .. } = event { intercepted_id != ev_id diff --git a/lightning/src/ln/functional_test_utils.rs b/lightning/src/ln/functional_test_utils.rs index 3abf34c9b63..2926f589a9f 100644 --- a/lightning/src/ln/functional_test_utils.rs +++ b/lightning/src/ln/functional_test_utils.rs @@ -860,7 +860,7 @@ macro_rules! get_monitor { for index in 0..2 { if let Ok(mon) = $node.chain_monitor.chain_monitor.get_monitor( $crate::chain::transaction::OutPoint { - txid: bitcoin::Txid::from_slice(&$channel_id.bytes()[..][..]).unwrap(), index + txid: bitcoin::Txid::from_slice(&$channel_id.bytes()[..]).unwrap(), index }) { monitor = Some(mon); diff --git a/lightning/src/ln/functional_tests.rs b/lightning/src/ln/functional_tests.rs index 828b053b912..c72e6eddfe9 100644 --- a/lightning/src/ln/functional_tests.rs +++ b/lightning/src/ln/functional_tests.rs @@ -1506,7 +1506,7 @@ fn test_fee_spike_violation_fails_htlc() { _ => panic!("Unexpected event"), }; nodes[1].logger.assert_log("lightning::ln::channel".to_string(), - format!("Attempting to fail HTLC due to fee spike buffer violation in channel {}. Rebalancing is required.", ::hex::encode(raa_msg.channel_id.bytes())), 1); + format!("Attempting to fail HTLC due to fee spike buffer violation in channel {}. Rebalancing is required.", raa_msg.channel_id), 1); check_added_monitors!(nodes[1], 2); } @@ -8003,7 +8003,7 @@ fn test_can_not_accept_unknown_inbound_channel() { let api_res = nodes[0].node.accept_inbound_channel(&unknown_channel_id, &nodes[1].node.get_our_node_id(), 0); match api_res { Err(APIError::ChannelUnavailable { err }) => { - assert_eq!(err, format!("Channel with id {} not found for the passed counterparty node_id {}", log_bytes!(unknown_channel_id.bytes()[..]), nodes[1].node.get_our_node_id())); + assert_eq!(err, format!("Channel with id {} not found for the passed counterparty node_id {}", &unknown_channel_id, nodes[1].node.get_our_node_id())); }, Ok(_) => panic!("It shouldn't be possible to accept an unkown channel"), Err(_) => panic!("Unexpected Error"), diff --git a/lightning/src/ln/payment_tests.rs b/lightning/src/ln/payment_tests.rs index 9bb764b90e7..6e42194e271 100644 --- a/lightning/src/ln/payment_tests.rs +++ b/lightning/src/ln/payment_tests.rs @@ -1732,7 +1732,7 @@ fn do_test_intercepted_payment(test: InterceptTest) { let unusable_chan_err = nodes[1].node.forward_intercepted_htlc(intercept_id, &temp_chan_id, nodes[2].node.get_our_node_id(), expected_outbound_amount_msat).unwrap_err(); assert_eq!(unusable_chan_err , APIError::ChannelUnavailable { err: format!("Funded channel with id {} not found for the passed counterparty node_id {}. Channel may still be opening.", - log_bytes!(temp_chan_id.bytes()[..]), nodes[2].node.get_our_node_id()) }); + &temp_chan_id, nodes[2].node.get_our_node_id()) }); assert_eq!(nodes[1].node.get_and_clear_pending_msg_events().len(), 1); // Open the just-in-time channel so the payment can then be forwarded. diff --git a/lightning/src/ln/peer_handler.rs b/lightning/src/ln/peer_handler.rs index 86fdb692bcc..4c5f3db7b3d 100644 --- a/lightning/src/ln/peer_handler.rs +++ b/lightning/src/ln/peer_handler.rs @@ -1914,31 +1914,31 @@ impl { log_debug!(self.logger, "Handling SendAcceptChannel event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.temporary_channel_id.bytes()[..])); + &msg.temporary_channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendAcceptChannelV2 { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendAcceptChannelV2 event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.temporary_channel_id.bytes()[..])); + &msg.temporary_channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendOpenChannel { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendOpenChannel event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.temporary_channel_id.bytes()[..])); + &msg.temporary_channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendOpenChannelV2 { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendOpenChannelV2 event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.temporary_channel_id.bytes()[..])); + &msg.temporary_channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendFundingCreated { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendFundingCreated event in peer_handler for node {} for channel {} (which becomes {})", log_pubkey!(node_id), - log_bytes!(msg.temporary_channel_id.bytes()[..]), + &msg.temporary_channel_id, log_funding_channel_id!(msg.funding_txid, msg.funding_output_index)); // TODO: If the peer is gone we should generate a DiscardFunding event // indicating to the wallet that they should just throw away this funding transaction @@ -1947,73 +1947,73 @@ impl { log_debug!(self.logger, "Handling SendFundingSigned event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendChannelReady { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendChannelReady event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendTxAddInput { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendTxAddInput event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendTxAddOutput { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendTxAddOutput event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendTxRemoveInput { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendTxRemoveInput event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendTxRemoveOutput { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendTxRemoveOutput event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendTxComplete { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendTxComplete event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendTxSignatures { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendTxSignatures event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendTxInitRbf { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendTxInitRbf event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendTxAckRbf { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendTxAckRbf event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendTxAbort { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendTxAbort event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendAnnouncementSignatures { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendAnnouncementSignatures event in peer_handler for node {} for channel {})", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::UpdateHTLCs { ref node_id, updates: msgs::CommitmentUpdate { ref update_add_htlcs, ref update_fulfill_htlcs, ref update_fail_htlcs, ref update_fail_malformed_htlcs, ref update_fee, ref commitment_signed } } => { @@ -2022,7 +2022,7 @@ impl { log_debug!(self.logger, "Handling SendRevokeAndACK event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendClosingSigned { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendClosingSigned event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendShutdown { ref node_id, ref msg } => { log_debug!(self.logger, "Handling Shutdown event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendChannelReestablish { ref node_id, ref msg } => { log_debug!(self.logger, "Handling SendChannelReestablish event in peer_handler for node {} for channel {}", log_pubkey!(node_id), - log_bytes!(msg.channel_id.bytes()[..])); + &msg.channel_id); self.enqueue_message(&mut *get_peer_for_forwarding!(node_id), msg); }, MessageSendEvent::SendChannelAnnouncement { ref node_id, ref msg, ref update_msg } => { diff --git a/lightning/src/util/macro_logger.rs b/lightning/src/util/macro_logger.rs index 32033b02b6d..4836b4d6814 100644 --- a/lightning/src/util/macro_logger.rs +++ b/lightning/src/util/macro_logger.rs @@ -15,7 +15,6 @@ use bitcoin::blockdata::transaction::Transaction; use crate::routing::router::Route; use crate::ln::chan_utils::HTLCClaim; -use crate::util::logger::DebugBytes; macro_rules! log_iter { ($obj: expr) => { @@ -42,10 +41,7 @@ macro_rules! log_bytes { pub(crate) struct DebugFundingChannelId<'a>(pub &'a Txid, pub u16); impl<'a> core::fmt::Display for DebugFundingChannelId<'a> { fn fmt(&self, f: &mut core::fmt::Formatter) -> Result<(), core::fmt::Error> { - for i in (OutPoint { txid: self.0.clone(), index: self.1 }).to_channel_id().bytes().iter() { - write!(f, "{:02x}", i)?; - } - Ok(()) + (OutPoint { txid: self.0.clone(), index: self.1 }).to_channel_id().fmt(f) } } macro_rules! log_funding_channel_id { @@ -57,7 +53,7 @@ macro_rules! log_funding_channel_id { pub(crate) struct DebugFundingInfo<'a, T: 'a>(pub &'a (OutPoint, T)); impl<'a, T> core::fmt::Display for DebugFundingInfo<'a, T> { fn fmt(&self, f: &mut core::fmt::Formatter) -> Result<(), core::fmt::Error> { - DebugBytes(&(self.0).0.to_channel_id().bytes()[..][..]).fmt(f) + (self.0).0.to_channel_id().fmt(f) } } macro_rules! log_funding_info {