From 7fa7641febd22b4f1475896bc2e1f5d32c57ac92 Mon Sep 17 00:00:00 2001 From: Lucas Soriano del Pino Date: Fri, 30 Oct 2020 15:51:46 +1100 Subject: [PATCH] Clean up some logs and comments --- swap/src/alice.rs | 76 +++++++++++++++++++------------------- swap/src/alice/amounts.rs | 4 +- swap/src/alice/message0.rs | 7 ++-- swap/src/alice/message1.rs | 3 +- swap/src/alice/message2.rs | 3 +- swap/src/alice/message3.rs | 4 +- swap/src/bob.rs | 58 +++++++++++++++-------------- swap/src/bob/amounts.rs | 3 +- swap/src/bob/message0.rs | 3 +- swap/src/bob/message1.rs | 3 +- swap/src/bob/message2.rs | 3 +- swap/src/bob/message3.rs | 2 - swap/src/main.rs | 1 - 13 files changed, 88 insertions(+), 82 deletions(-) diff --git a/swap/src/alice.rs b/swap/src/alice.rs index 8fa41f0c..4e57c135 100644 --- a/swap/src/alice.rs +++ b/swap/src/alice.rs @@ -12,8 +12,7 @@ use libp2p::{ use rand::rngs::OsRng; use std::{sync::Arc, time::Duration}; use tokio::sync::Mutex; -use tracing::{info, warn}; -use xmr_btc::alice; +use tracing::{debug, info, warn}; mod amounts; mod message0; @@ -34,14 +33,12 @@ use crate::{ SwapAmounts, PUNISH_TIMELOCK, REFUND_TIMELOCK, }; use xmr_btc::{ - alice::{action_generator, Action, ReceiveBitcoinRedeemEncsig, State0}, + alice::{self, action_generator, Action, ReceiveBitcoinRedeemEncsig, State0}, bitcoin::BroadcastSignedTransaction, bob, monero::{CreateWalletForOutput, Transfer}, }; -pub type Swarm = libp2p::Swarm; - pub async fn swap( bitcoin_wallet: Arc, monero_wallet: Arc, @@ -55,15 +52,14 @@ pub async fn swap( impl Network { pub async fn send_message2(&mut self, proof: monero::TransferProof) { - tracing::debug!("Sending transfer proof"); - match self.channel.take() { None => warn!("Channel not found, did you call this twice?"), Some(channel) => { let mut guard = self.swarm.lock().await; guard.send_message2(channel, alice::Message2 { tx_lock_proof: proof, - }) + }); + info!("Sent transfer proof"); } } } @@ -78,17 +74,12 @@ pub async fn swap( #[derive(Debug)] struct UnexpectedMessage; - tracing::debug!("Receiving bitcoin redeem encsig"); - - (|| async { + let encsig = (|| async { let mut guard = self.swarm.lock().await; let encsig = match guard.next().await { - OutEvent::Message3(msg) => { - tracing::debug!("Got redeem encsig from Bob"); - msg.tx_redeem_encsig - } + OutEvent::Message3(msg) => msg.tx_redeem_encsig, other => { - warn!("Expected Bob's Message3, got: {:?}", other); + warn!("Expected Bob's Bitcoin redeem encsig, got: {:?}", other); return Err(backoff::Error::Transient(UnexpectedMessage)); } }; @@ -97,33 +88,35 @@ pub async fn swap( }) .retry(ConstantBackoff::new(Duration::from_secs(1))) .await - .expect("transient errors to be retried") + .expect("transient errors to be retried"); + + info!("Received Bitcoin redeem encsig"); + + encsig } } - tracing::debug!("swapping ..."); - let mut swarm = new_swarm(listen, local_port)?; let message0: bob::Message0; let mut state0: Option = None; let mut last_amounts: Option = None; + // TODO: This loop is a neat idea for local development, as it allows us to keep + // Alice up and let Bob keep trying to connect, request amounts and/or send the + // first message of the handshake, but it comes at the cost of needing to handle + // mutable state, which has already been the source of a bug at one point. This + // is an obvious candidate for refactoring loop { match swarm.next().await { - OutEvent::ConnectionEstablished(id) => { - info!("Connection established with: {}", id); + OutEvent::ConnectionEstablished(bob) => { + info!("Connection established with: {}", bob); } OutEvent::Request(amounts::OutEvent::Btc { btc, channel }) => { let amounts = calculate_amounts(btc); - // TODO: We cache the last amounts returned, this needs improving along with - // verification of message 0. last_amounts = Some(amounts); swarm.send_amounts(channel, amounts); - let (xmr, btc) = match last_amounts { - Some(p) => (p.xmr, p.btc), - None => unreachable!("should have amounts by here"), - }; + let SwapAmounts { btc, xmr } = amounts; let redeem_address = bitcoin_wallet.as_ref().new_address().await?; let punish_address = redeem_address.clone(); @@ -139,6 +132,8 @@ pub async fn swap( redeem_address, punish_address, ); + + info!("Commencing handshake"); swarm.set_state0(state.clone()); state0 = Some(state) @@ -156,10 +151,7 @@ pub async fn swap( }; } - let state1 = state0 - .expect("to be set") - .receive(message0) - .expect("failed to receive msg 0"); + let state1 = state0.expect("to be set").receive(message0)?; let (state2, channel) = match swarm.next().await { OutEvent::Message1 { msg, channel } => { @@ -197,7 +189,7 @@ pub async fn swap( loop { let state = action_generator.async_resume().await; - tracing::info!("resumed execution of alice generator, got: {:?}", state); + tracing::info!("Resumed execution of generator, got: {:?}", state); match state { GeneratorState::Yielded(Action::LockXmr { @@ -211,6 +203,7 @@ pub async fn swap( let mut guard = network.as_ref().lock().await; guard.send_message2(transfer_proof).await; + info!("Sent transfer proof"); } GeneratorState::Yielded(Action::RedeemBtc(tx)) => { @@ -235,6 +228,8 @@ pub async fn swap( } } +pub type Swarm = libp2p::Swarm; + fn new_swarm(listen: Multiaddr, port: Option) -> Result { use anyhow::Context as _; @@ -366,11 +361,12 @@ impl Alice { pub fn send_amounts(&mut self, channel: ResponseChannel, amounts: SwapAmounts) { let msg = AliceToBob::Amounts(amounts); self.amounts.send(channel, msg); + info!("Sent amounts response"); } /// Message0 gets sent within the network layer using this state0. pub fn set_state0(&mut self, state: State0) { - info!("Set state 0"); + debug!("Set state 0"); let _ = self.message0.set_state(state); } @@ -380,7 +376,8 @@ impl Alice { channel: ResponseChannel, msg: xmr_btc::alice::Message1, ) { - self.message1.send(channel, msg) + self.message1.send(channel, msg); + debug!("Sent Message1"); } /// Send Message2 to Bob in response to receiving his Message2. @@ -389,7 +386,8 @@ impl Alice { channel: ResponseChannel, msg: xmr_btc::alice::Message2, ) { - self.message2.send(channel, msg) + self.message2.send(channel, msg); + debug!("Sent Message2"); } } @@ -410,11 +408,11 @@ impl Default for Alice { } fn calculate_amounts(btc: ::bitcoin::Amount) -> SwapAmounts { - const XMR_PER_BTC: u64 = 100; // TODO: Get this from an exchange. + // TODO: Get this from an exchange. + // This value corresponds to 100 XMR per BTC + const PICONERO_PER_SAT: u64 = 1_000_000; - // TODO: Check that this is correct. - // XMR uses 12 zerose BTC uses 8. - let picos = (btc.as_sat() * 10000) * XMR_PER_BTC; + let picos = btc.as_sat() * PICONERO_PER_SAT; let xmr = monero::Amount::from_piconero(picos); SwapAmounts { btc, xmr } diff --git a/swap/src/alice/amounts.rs b/swap/src/alice/amounts.rs index 85dd5b92..33e230d5 100644 --- a/swap/src/alice/amounts.rs +++ b/swap/src/alice/amounts.rs @@ -11,7 +11,7 @@ use std::{ task::{Context, Poll}, time::Duration, }; -use tracing::error; +use tracing::{debug, error}; use crate::network::request_response::{AliceToBob, AmountsProtocol, BobToAlice, Codec, TIMEOUT}; @@ -80,8 +80,8 @@ impl NetworkBehaviourEventProcess> }, .. } => { - tracing::debug!("amounts: Request from Bob received"); if let BobToAlice::AmountsFromBtc(btc) = request { + debug!("Received amounts request"); self.events.push_back(OutEvent::Btc { btc, channel }) } } diff --git a/swap/src/alice/message0.rs b/swap/src/alice/message0.rs index 45bb248c..b10b3aca 100644 --- a/swap/src/alice/message0.rs +++ b/swap/src/alice/message0.rs @@ -13,7 +13,7 @@ use std::{ task::{Context, Poll}, time::Duration, }; -use tracing::{error, info}; +use tracing::{debug, error}; use crate::network::request_response::{AliceToBob, BobToAlice, Codec, Message0Protocol, TIMEOUT}; use xmr_btc::{alice::State0, bob}; @@ -86,9 +86,8 @@ impl NetworkBehaviourEventProcess> }, .. } => { - tracing::debug!("message0: Request from Bob received"); if let BobToAlice::Message0(msg) = request { - info!("Got Bob's first message"); + debug!("Received Message0"); let response = match &self.state { None => panic!("No state, did you forget to set it?"), Some(state) => { @@ -97,6 +96,8 @@ impl NetworkBehaviourEventProcess> } }; self.rr.send_response(channel, response); + debug!("Sent Message0"); + self.events.push_back(OutEvent::Msg(msg)); } } diff --git a/swap/src/alice/message1.rs b/swap/src/alice/message1.rs index 11e578ad..4d44b0a2 100644 --- a/swap/src/alice/message1.rs +++ b/swap/src/alice/message1.rs @@ -11,7 +11,7 @@ use std::{ task::{Context, Poll}, time::Duration, }; -use tracing::error; +use tracing::{debug, error}; use crate::network::request_response::{AliceToBob, BobToAlice, Codec, Message1Protocol, TIMEOUT}; use xmr_btc::bob; @@ -83,6 +83,7 @@ impl NetworkBehaviourEventProcess> .. } => { if let BobToAlice::Message1(msg) = request { + debug!("Received Message1"); self.events.push_back(OutEvent::Msg { msg, channel }); } } diff --git a/swap/src/alice/message2.rs b/swap/src/alice/message2.rs index e1493ba4..bab62d3e 100644 --- a/swap/src/alice/message2.rs +++ b/swap/src/alice/message2.rs @@ -11,7 +11,7 @@ use std::{ task::{Context, Poll}, time::Duration, }; -use tracing::error; +use tracing::{debug, error}; use crate::network::request_response::{AliceToBob, BobToAlice, Codec, Message2Protocol, TIMEOUT}; use xmr_btc::bob; @@ -83,6 +83,7 @@ impl NetworkBehaviourEventProcess> .. } => { if let BobToAlice::Message2(msg) = request { + debug!("Received Message2"); self.events.push_back(OutEvent::Msg { msg, channel }); } } diff --git a/swap/src/alice/message3.rs b/swap/src/alice/message3.rs index 808f5639..0e4bd773 100644 --- a/swap/src/alice/message3.rs +++ b/swap/src/alice/message3.rs @@ -11,7 +11,7 @@ use std::{ task::{Context, Poll}, time::Duration, }; -use tracing::error; +use tracing::{debug, error}; use crate::network::request_response::{AliceToBob, BobToAlice, Codec, Message3Protocol, TIMEOUT}; use xmr_btc::bob; @@ -73,7 +73,7 @@ impl NetworkBehaviourEventProcess> .. } => { if let BobToAlice::Message3(msg) = request { - tracing::debug!("Alice: got message 3 from Bob"); + debug!("Received Message3"); self.events.push_back(OutEvent::Msg(msg)); // Send back empty response so that the request/response protocol completes. self.rr.send_response(channel, AliceToBob::Message3); diff --git a/swap/src/bob.rs b/swap/src/bob.rs index aa4f2e7c..451fc200 100644 --- a/swap/src/bob.rs +++ b/swap/src/bob.rs @@ -38,7 +38,6 @@ use xmr_btc::{ monero::CreateWalletForOutput, }; -// FIXME: This whole function is horrible, needs total re-write. pub async fn swap( bitcoin_wallet: Arc, monero_wallet: Arc, @@ -58,18 +57,13 @@ pub async fn swap( #[derive(Debug)] struct UnexpectedMessage; - tracing::debug!("Receiving transfer proof"); - let future = self.0.next().shared(); - (|| async { + let proof = (|| async { let proof = match future.clone().await { - OutEvent::Message2(msg) => { - debug!("Got transfer proof from Alice"); - msg.tx_lock_proof - } + OutEvent::Message2(msg) => msg.tx_lock_proof, other => { - warn!("Expected Alice's Message2, got: {:?}", other); + warn!("Expected transfer proof, got: {:?}", other); return Err(backoff::Error::Transient(UnexpectedMessage)); } }; @@ -78,12 +72,14 @@ pub async fn swap( }) .retry(ConstantBackoff::new(Duration::from_secs(1))) .await - .expect("transient errors to be retried") + .expect("transient errors to be retried"); + + info!("Received transfer proof"); + + proof } } - debug!("swapping ..."); - let mut swarm = new_swarm()?; libp2p::Swarm::dial_addr(&mut swarm, addr)?; @@ -91,22 +87,22 @@ pub async fn swap( OutEvent::ConnectionEstablished(alice) => alice, other => panic!("unexpected event: {:?}", other), }; - info!("Connection established."); + info!("Connection established with: {}", alice); swarm.request_amounts(alice.clone(), btc); - let (btc_amount, xmr) = match swarm.next().await { + let (btc, xmr) = match swarm.next().await { OutEvent::Amounts(amounts) => { - debug!("Got amounts from Alice: {:?}", amounts); + info!("Got amounts from Alice: {:?}", amounts); let cmd = Cmd::VerifyAmounts(amounts); cmd_tx.try_send(cmd)?; let response = rsp_rx.next().await; if response == Some(Rsp::Abort) { - info!("Amounts no good, aborting ..."); + info!("User rejected amounts proposed by Alice, aborting..."); process::exit(0); } - info!("User verified amounts, continuing with swap ..."); + info!("User accepted amounts proposed by Alice"); (amounts.btc, amounts.xmr) } other => panic!("unexpected event: {:?}", other), @@ -118,13 +114,15 @@ pub async fn swap( let rng = &mut OsRng; let state0 = State0::new( rng, - btc_amount, + btc, xmr, REFUND_TIMELOCK, PUNISH_TIMELOCK, refund_address, ); + info!("Commencing handshake"); + swarm.send_message0(alice.clone(), state0.next_message(rng)); let state1 = match swarm.next().await { OutEvent::Message0(msg) => state0.receive(bitcoin_wallet.as_ref(), msg).await?, @@ -141,7 +139,7 @@ pub async fn swap( swarm.send_message2(alice.clone(), state2.next_message()); - info!("Handshake complete, we now have State2 for Bob."); + info!("Handshake complete"); let network = Arc::new(Mutex::new(Network(swarm))); @@ -156,7 +154,7 @@ pub async fn swap( loop { let state = action_generator.async_resume().await; - info!("resumed execution of bob generator, got: {:?}", state); + info!("Resumed execution of generator, got: {:?}", state); match state { GeneratorState::Yielded(bob::Action::LockBtc(tx_lock)) => { @@ -167,11 +165,14 @@ pub async fn swap( } GeneratorState::Yielded(bob::Action::SendBtcRedeemEncsig(tx_redeem_encsig)) => { let mut guard = network.as_ref().lock().await; - debug!("Bob: sending message 3"); guard.0.send_message3(alice.clone(), tx_redeem_encsig); + info!("Sent Bitcoin redeem encsig"); + + // TODO: Does Bob need to wait for Alice to send an empty response, or can we + // just continue? match guard.0.next().shared().await { OutEvent::Message3 => { - debug!("Got message 3 response from Alice"); + debug!("Got Message3 empty response"); } other => panic!("unexpected event: {:?}", other), }; @@ -318,29 +319,32 @@ impl Bob { pub fn request_amounts(&mut self, alice: PeerId, btc: u64) { let btc = ::bitcoin::Amount::from_sat(btc); let _id = self.amounts.request_amounts(alice.clone(), btc); - debug!("Requesting amounts from: {}", alice); + info!("Requesting amounts from: {}", alice); } /// Sends Bob's first message to Alice. pub fn send_message0(&mut self, alice: PeerId, msg: bob::Message0) { self.message0.send(alice, msg); - info!("Sent first message to Alice"); + debug!("Sent Message0"); } /// Sends Bob's second message to Alice. pub fn send_message1(&mut self, alice: PeerId, msg: bob::Message1) { - self.message1.send(alice, msg) + self.message1.send(alice, msg); + debug!("Sent Message1"); } /// Sends Bob's third message to Alice. pub fn send_message2(&mut self, alice: PeerId, msg: bob::Message2) { - self.message2.send(alice, msg) + self.message2.send(alice, msg); + debug!("Sent Message2"); } /// Sends Bob's fourth message to Alice. pub fn send_message3(&mut self, alice: PeerId, tx_redeem_encsig: EncryptedSignature) { let msg = bob::Message3 { tx_redeem_encsig }; - self.message3.send(alice, msg) + self.message3.send(alice, msg); + debug!("Sent Message3"); } /// Returns Alice's peer id if we are connected. diff --git a/swap/src/bob/amounts.rs b/swap/src/bob/amounts.rs index f2fd0266..7428ad30 100644 --- a/swap/src/bob/amounts.rs +++ b/swap/src/bob/amounts.rs @@ -12,7 +12,7 @@ use std::{ task::{Context, Poll}, time::Duration, }; -use tracing::error; +use tracing::{debug, error}; use crate::{ network::request_response::{AliceToBob, AmountsProtocol, BobToAlice, Codec, TIMEOUT}, @@ -85,6 +85,7 @@ impl NetworkBehaviourEventProcess> .. } => { if let AliceToBob::Amounts(p) = response { + debug!("Received amounts response"); self.events.push_back(OutEvent::Amounts(p)); } } diff --git a/swap/src/bob/message0.rs b/swap/src/bob/message0.rs index 455b7452..89504fbb 100644 --- a/swap/src/bob/message0.rs +++ b/swap/src/bob/message0.rs @@ -11,7 +11,7 @@ use std::{ task::{Context, Poll}, time::Duration, }; -use tracing::error; +use tracing::{debug, error}; use crate::network::request_response::{AliceToBob, BobToAlice, Codec, Message0Protocol, TIMEOUT}; use xmr_btc::{alice, bob}; @@ -79,6 +79,7 @@ impl NetworkBehaviourEventProcess> .. } => { if let AliceToBob::Message0(msg) = response { + debug!("Received Message0"); self.events.push_back(OutEvent::Msg(msg)); } } diff --git a/swap/src/bob/message1.rs b/swap/src/bob/message1.rs index e3a67de9..32fd6c52 100644 --- a/swap/src/bob/message1.rs +++ b/swap/src/bob/message1.rs @@ -11,7 +11,7 @@ use std::{ task::{Context, Poll}, time::Duration, }; -use tracing::error; +use tracing::{debug, error}; use crate::network::request_response::{AliceToBob, BobToAlice, Codec, Message1Protocol, TIMEOUT}; use xmr_btc::{alice, bob}; @@ -79,6 +79,7 @@ impl NetworkBehaviourEventProcess> .. } => { if let AliceToBob::Message1(msg) = response { + debug!("Received Message1"); self.events.push_back(OutEvent::Msg(msg)); } } diff --git a/swap/src/bob/message2.rs b/swap/src/bob/message2.rs index b141b240..17425227 100644 --- a/swap/src/bob/message2.rs +++ b/swap/src/bob/message2.rs @@ -11,7 +11,7 @@ use std::{ task::{Context, Poll}, time::Duration, }; -use tracing::error; +use tracing::{debug, error}; use crate::network::request_response::{AliceToBob, BobToAlice, Codec, Message2Protocol, TIMEOUT}; use xmr_btc::{alice, bob}; @@ -79,6 +79,7 @@ impl NetworkBehaviourEventProcess> .. } => { if let AliceToBob::Message2(msg) = response { + debug!("Received Message2"); self.events.push_back(OutEvent::Msg(msg)); } } diff --git a/swap/src/bob/message3.rs b/swap/src/bob/message3.rs index 525912d1..20873bfa 100644 --- a/swap/src/bob/message3.rs +++ b/swap/src/bob/message3.rs @@ -34,7 +34,6 @@ pub struct Message3 { impl Message3 { pub fn send(&mut self, alice: PeerId, msg: bob::Message3) { let msg = BobToAlice::Message3(msg); - tracing::debug!("sending ..."); let _id = self.rr.send_request(&alice, msg); } @@ -81,7 +80,6 @@ impl NetworkBehaviourEventProcess> } => { if let AliceToBob::Message3 = response { self.events.push_back(OutEvent::Msg); - tracing::debug!("Alice correctly responded to message 3"); } } RequestResponseEvent::InboundFailure { error, .. } => { diff --git a/swap/src/main.rs b/swap/src/main.rs index a813aa62..c2b0b4b6 100644 --- a/swap/src/main.rs +++ b/swap/src/main.rs @@ -28,7 +28,6 @@ use cli::Options; use swap::{alice, bitcoin, bob, monero, Cmd, Rsp, SwapAmounts}; // TODO: Add root seed file instead of generating new seed each run. -// TODO: Remove all instances of the todo! macro // TODO: Add a config file with these in it. // Alice's address and port until we have a config file.