diff --git a/mutiny-core/src/auth.rs b/mutiny-core/src/auth.rs index b3caed607..7088b2d31 100644 --- a/mutiny-core/src/auth.rs +++ b/mutiny-core/src/auth.rs @@ -6,16 +6,17 @@ use crate::{ networking::websocket::{SimpleWebSocket, WebSocketImpl}, utils, }; +use async_lock::RwLock; use jwt_compact::UntrustedToken; use lightning::util::logger::*; -use lightning::{log_error, log_info}; +use lightning::{log_debug, log_error, log_info}; use lnurl::{lnurl::LnUrl, AsyncClient as LnUrlClient}; use reqwest::Client; use reqwest::{Method, StatusCode, Url}; use serde::{Deserialize, Serialize}; use serde_json::Value; use std::str::FromStr; -use std::sync::{Arc, RwLock}; +use std::sync::Arc; #[derive(Debug, PartialEq, Serialize, Deserialize)] struct CustomClaims { @@ -54,8 +55,9 @@ impl MutinyAuthClient { Ok(()) } - pub fn is_authenticated(&self) -> Option { - if let Some(ref jwt) = *self.jwt.try_read().unwrap() { + pub async fn is_authenticated(&self) -> Option { + let lock = self.jwt.read().await; + if let Some(jwt) = lock.as_ref() { return Some(jwt.to_string()); // TODO parse and make sure still valid } None @@ -92,7 +94,7 @@ impl MutinyAuthClient { ) -> Result { let mut request = self.http_client.request(method, url); - let mut jwt = self.is_authenticated(); + let mut jwt = self.is_authenticated().await; if jwt.is_none() { jwt = Some(self.retrieve_new_jwt().await?); } @@ -110,6 +112,10 @@ impl MutinyAuthClient { } async fn retrieve_new_jwt(&self) -> Result { + // get lock so we don't make multiple requests for the same token + let mut lock = self.jwt.write().await; + log_debug!(self.logger, "Retrieving new JWT token"); + let mut url = Url::parse(&self.url).map_err(|_| MutinyError::LnUrlFailure)?; let ws_scheme = match url.scheme() { "http" => "ws", @@ -165,7 +171,7 @@ impl MutinyAuthClient { }; log_info!(self.logger, "Retrieved new JWT token"); - *self.jwt.try_write()? = Some(jwt.clone()); + *lock = Some(jwt.clone()); Ok(jwt) } } @@ -201,7 +207,7 @@ mod tests { // Test authenticate method match auth_client.authenticate().await { - Ok(_) => assert!(auth_client.is_authenticated().is_some()), + Ok(_) => assert!(auth_client.is_authenticated().await.is_some()), Err(e) => panic!("Authentication failed with error: {:?}", e), }; diff --git a/mutiny-core/src/federation.rs b/mutiny-core/src/federation.rs index 0b75c6208..fe787d464 100644 --- a/mutiny-core/src/federation.rs +++ b/mutiny-core/src/federation.rs @@ -1,3 +1,4 @@ +use crate::utils::spawn; use crate::{ error::{MutinyError, MutinyStorageError}, event::PaymentInfo, @@ -55,11 +56,15 @@ use fedimint_wallet_client::{WalletClientInit, WalletClientModule}; use futures::future::{self}; use futures_util::{pin_mut, StreamExt}; use hex::FromHex; +#[cfg(target_arch = "wasm32")] +use instant::Instant; use lightning::{ ln::PaymentHash, log_debug, log_error, log_info, log_trace, log_warn, util::logger::Logger, }; use lightning_invoice::{Bolt11Invoice, RoutingFees}; use serde::{de::DeserializeOwned, Deserialize, Serialize}; +#[cfg(not(target_arch = "wasm32"))] +use std::time::Instant; use std::{collections::HashMap, fmt::Debug, sync::Arc}; use std::{ str::FromStr, @@ -192,18 +197,7 @@ impl FederationClient { ) -> Result { log_info!(logger, "initializing a new federation client: {uuid}"); - let federation_info = FederationInfo::from_invite_code(federation_code.clone()) - .await - .map_err(|e| { - log_error!(logger, "Could not parse invite code: {}", e); - e - })?; - - log_debug!( - logger, - "parsed federation invite code: {:?}", - federation_info.invite_code() - ); + let federation_id = federation_code.federation_id(); let mut client_builder = fedimint_client::Client::builder(); client_builder.with_module(WalletClientInit(None)); @@ -211,16 +205,31 @@ impl FederationClient { client_builder.with_module(LightningClientInit); log_trace!(logger, "Building fedimint client db"); - let fedimint_storage = FedimintStorage::new( - storage.clone(), - federation_info.federation_id().to_string(), - logger.clone(), - ) - .await?; + let fedimint_storage = + FedimintStorage::new(storage.clone(), federation_id.to_string(), logger.clone()) + .await?; let db = fedimint_storage.clone().into(); if get_config_from_db(&db).await.is_none() { - client_builder.with_federation_info(federation_info.clone()); + let download = Instant::now(); + let federation_info = FederationInfo::from_invite_code(federation_code) + .await + .map_err(|e| { + log_error!(logger, "Could not parse invite code: {}", e); + e + })?; + log_trace!( + logger, + "Downloaded federation info in: {}ms", + download.elapsed().as_millis() + ); + + log_debug!( + logger, + "parsed federation invite code: {:?}", + federation_info.invite_code() + ); + client_builder.with_federation_info(federation_info); } client_builder.with_database(db); @@ -230,10 +239,7 @@ impl FederationClient { let secret = create_federation_secret(xprivkey, network)?; let fedimint_client = client_builder - .build(get_default_client_secret( - &secret, - &federation_info.federation_id(), - )) + .build(get_default_client_secret(&secret, &federation_id)) .await?; log_trace!(logger, "Retrieving fedimint wallet client module"); @@ -249,36 +255,43 @@ impl FederationClient { return Err(MutinyError::NetworkMismatch); } - // Set active gateway preference - let lightning_module = fedimint_client.get_first_module::(); - let gateways = lightning_module - .fetch_registered_gateways() - .await - .map_err(|e| { - log_warn!( - logger, - "Could not fetch gateways from federation {}: {e}", - federation_info.federation_id() - ) - }); - - if let Ok(gateways) = gateways { - if let Some(a) = get_gateway_preference(gateways, fedimint_client.federation_id()) { - log_info!( - logger, - "Setting active gateway for federation {}: {:?}", - federation_info.federation_id(), - a - ); - let _ = lightning_module.set_active_gateway(&a).await.map_err(|e| { + // Set active gateway preference in background + let client_clone = fedimint_client.clone(); + let logger_clone = logger.clone(); + spawn(async move { + let start = Instant::now(); + let lightning_module = client_clone.get_first_module::(); + let gateways = lightning_module + .fetch_registered_gateways() + .await + .map_err(|e| { log_warn!( - logger, - "Could not set gateway for federation {}: {e}", - federation_info.federation_id() + logger_clone, + "Could not fetch gateways from federation {federation_id}: {e}", ) }); + + if let Ok(gateways) = gateways { + if let Some(a) = get_gateway_preference(gateways, federation_id) { + log_info!( + logger_clone, + "Setting active gateway for federation {federation_id}: {a}" + ); + let _ = lightning_module.set_active_gateway(&a).await.map_err(|e| { + log_warn!( + logger_clone, + "Could not set gateway for federation {federation_id}: {e}", + ) + }); + } } - } + + log_trace!( + logger_clone, + "Setting active gateway took: {}ms", + start.elapsed().as_millis() + ); + }); log_debug!(logger, "Built fedimint client"); Ok(FederationClient { diff --git a/mutiny-core/src/gossip.rs b/mutiny-core/src/gossip.rs index 2c7bf1b23..02079d919 100644 --- a/mutiny-core/src/gossip.rs +++ b/mutiny-core/src/gossip.rs @@ -4,17 +4,21 @@ use crate::{ }; use bitcoin::hashes::hex::{FromHex, ToHex}; use bitcoin::Network; +#[cfg(target_arch = "wasm32")] +use instant::Instant; use lightning::ln::msgs::NodeAnnouncement; use lightning::routing::gossip::NodeId; use lightning::util::logger::Logger; use lightning::util::ser::ReadableArgs; -use lightning::{log_debug, log_error, log_info, log_warn}; +use lightning::{log_debug, log_error, log_info, log_trace, log_warn}; use reqwest::Client; use reqwest::{Method, Url}; use serde::{Deserialize, Serialize}; use std::collections::HashMap; use std::str::FromStr; use std::sync::Arc; +#[cfg(not(target_arch = "wasm32"))] +use std::time::Instant; use crate::logging::MutinyLogger; use crate::node::{NetworkGraph, RapidGossipSync}; @@ -105,7 +109,7 @@ pub struct Scorer { pub value: String, } -pub async fn get_remote_scorer_bytes( +async fn get_remote_scorer_bytes( auth_client: &MutinyAuthClient, base_url: &str, ) -> Result, MutinyError> { @@ -126,6 +130,29 @@ pub async fn get_remote_scorer_bytes( Ok(decoded) } +/// Gets the remote scorer from the server, parses it and returns it as a [`HubPreferentialScorer`] +pub async fn get_remote_scorer( + auth_client: &MutinyAuthClient, + base_url: &str, + network_graph: Arc, + logger: Arc, +) -> Result { + let start = Instant::now(); + let scorer_bytes = get_remote_scorer_bytes(auth_client, base_url).await?; + let mut readable_bytes = lightning::io::Cursor::new(scorer_bytes); + let params = decay_params(); + let args = (params, network_graph, logger.clone()); + let scorer = ProbScorer::read(&mut readable_bytes, args)?; + + log_trace!( + logger, + "Retrieved remote scorer in {}ms", + start.elapsed().as_millis() + ); + + Ok(HubPreferentialScorer::new(scorer)) +} + fn write_gossip_data( storage: &impl MutinyStorage, last_sync_timestamp: u32, @@ -142,9 +169,7 @@ fn write_gossip_data( } pub async fn get_gossip_sync( - _storage: &impl MutinyStorage, - remote_scorer_url: Option, - auth_client: Option>, + storage: &impl MutinyStorage, network: Network, logger: Arc, ) -> Result<(RapidGossipSync, HubPreferentialScorer), MutinyError> { @@ -158,37 +183,28 @@ pub async fn get_gossip_sync( gossip_data.last_sync_timestamp ); + let start = Instant::now(); + // get network graph let gossip_sync = RapidGossipSync::new(gossip_data.network_graph.clone(), logger.clone()); - // Try to get remote scorer if remote_scorer_url and auth_client are available - if let (Some(url), Some(client)) = (remote_scorer_url, &auth_client) { - match get_remote_scorer_bytes(client, &url).await { - Ok(scorer_bytes) => { - let mut readable_bytes = lightning::io::Cursor::new(scorer_bytes); - let params = decay_params(); - let args = ( - params, - Arc::clone(&gossip_data.network_graph), - Arc::clone(&logger), - ); - if let Ok(remote_scorer) = ProbScorer::read(&mut readable_bytes, args) { - log_debug!(logger, "retrieved remote scorer"); - let remote_scorer = HubPreferentialScorer::new(remote_scorer); - gossip_data.scorer = Some(remote_scorer); - } else { - log_error!( - logger, - "failed to parse remote scorer, keeping the local one" - ); - } - } - Err(_) => { - log_error!( - logger, - "failed to retrieve remote scorer, keeping the local one" - ); - } + let scorer_hex: Option = storage.get_data(PROB_SCORER_KEY)?; + + if let Some(hex) = scorer_hex { + let scorer_bytes: Vec = Vec::from_hex(&hex)?; + let mut readable_bytes = lightning::io::Cursor::new(scorer_bytes); + let params = decay_params(); + let args = ( + params, + Arc::clone(&gossip_data.network_graph), + Arc::clone(&logger), + ); + if let Ok(scorer) = ProbScorer::read(&mut readable_bytes, args) { + log_debug!(logger, "retrieved local scorer"); + let scorer = HubPreferentialScorer::new(scorer); + gossip_data.scorer = Some(scorer); + } else { + log_error!(logger, "failed to parse local scorer"); } } @@ -201,6 +217,11 @@ pub async fn get_gossip_sync( } }; + log_trace!( + &logger, + "Gossip sync/Scorer initialized in {}ms", + start.elapsed().as_millis() + ); Ok((gossip_sync, prob_scorer)) } @@ -550,7 +571,7 @@ mod test { let storage = MemoryStorage::default(); let logger = Arc::new(MutinyLogger::default()); - let _gossip_sync = get_gossip_sync(&storage, None, None, Network::Regtest, logger.clone()) + let _gossip_sync = get_gossip_sync(&storage, Network::Regtest, logger.clone()) .await .unwrap(); diff --git a/mutiny-core/src/lib.rs b/mutiny-core/src/lib.rs index c65baad1f..f40b671d9 100644 --- a/mutiny-core/src/lib.rs +++ b/mutiny-core/src/lib.rs @@ -86,15 +86,19 @@ use bitcoin::util::bip32::ExtendedPrivKey; use bitcoin::Network; use fedimint_core::{api::InviteCode, config::FederationId}; use futures::{pin_mut, select, FutureExt}; +#[cfg(target_arch = "wasm32")] +use instant::Instant; use lightning::ln::PaymentHash; -use lightning::{log_debug, util::logger::Logger}; -use lightning::{log_error, log_info, log_warn}; +use lightning::util::logger::Logger; +use lightning::{log_debug, log_error, log_info, log_trace, log_warn}; use lightning_invoice::{Bolt11Invoice, Bolt11InvoiceDescription}; use lnurl::{lnurl::LnUrl, AsyncClient as LnUrlClient, LnUrlResponse, Response}; use nostr_sdk::{Client, RelayPoolNotification}; use serde::{Deserialize, Serialize}; use serde_json::{json, Value}; use std::sync::Arc; +#[cfg(not(target_arch = "wasm32"))] +use std::time::Instant; use std::{collections::HashMap, sync::atomic::AtomicBool}; use std::{str::FromStr, sync::atomic::Ordering}; use uuid::Uuid; @@ -714,12 +718,21 @@ impl MutinyWalletBuilder { self.session_id, )); + let start = Instant::now(); + let mut nm_builder = NodeManagerBuilder::new(self.xprivkey, self.storage.clone()) .with_config(config.clone()); nm_builder.with_stop(stop.clone()); nm_builder.with_logger(logger.clone()); let node_manager = Arc::new(nm_builder.build().await?); + log_trace!( + logger, + "NodeManager started, took: {}ms", + start.elapsed().as_millis() + ); + + // start syncing node manager NodeManager::start_sync(node_manager.clone()); // create nostr manager @@ -738,7 +751,17 @@ impl MutinyWalletBuilder { // create federation module if any exist let federation_storage = self.storage.get_federations()?; let federations = if !federation_storage.federations.is_empty() { - create_federations(federation_storage.clone(), &config, &self.storage, &logger).await? + let start = Instant::now(); + log_trace!(logger, "Building Federations"); + let result = + create_federations(federation_storage.clone(), &config, &self.storage, &logger) + .await?; + log_debug!( + logger, + "Federations started, took: {}ms", + start.elapsed().as_millis() + ); + result } else { Arc::new(RwLock::new(HashMap::new())) }; @@ -750,6 +773,8 @@ impl MutinyWalletBuilder { ); } + let start = Instant::now(); + let lnurl_client = Arc::new( lnurl::Builder::default() .build_async() @@ -795,11 +820,18 @@ impl MutinyWalletBuilder { { // if we need a full sync from a restore if mw.storage.get(NEED_FULL_SYNC_KEY)?.unwrap_or_default() { + let start = Instant::now(); + log_info!(mw.logger, "Full sync needed from restore"); mw.node_manager .wallet .full_sync(crate::onchain::RESTORE_SYNC_STOP_GAP) .await?; mw.storage.delete(&[NEED_FULL_SYNC_KEY])?; + log_info!( + mw.logger, + "Full sync complete, took: {}ms", + start.elapsed().as_millis() + ); } } @@ -810,11 +842,14 @@ impl MutinyWalletBuilder { } // if we don't have any nodes, create one - match mw.node_manager.list_nodes().await?.pop() { - Some(_) => (), - None => { - mw.node_manager.new_node().await?; - } + if mw.node_manager.list_nodes().await?.is_empty() { + let nm = mw.node_manager.clone(); + // spawn in background, this can take a while and we don't want to block + utils::spawn(async move { + if let Err(e) = nm.new_node().await { + log_error!(nm.logger, "Failed to create first node: {e}"); + } + }) }; // start the nostr background process @@ -823,6 +858,12 @@ impl MutinyWalletBuilder { // start the federation background processor mw.start_fedimint_background_checker().await; + log_info!( + mw.logger, + "Final setup took {}ms", + start.elapsed().as_millis() + ); + Ok(mw) } } @@ -2231,12 +2272,11 @@ async fn create_federations( storage: &S, logger: &Arc, ) -> Result>>>>, MutinyError> { - let federations = federation_storage.federations.into_iter(); - let mut federation_map = HashMap::new(); - for federation_item in federations { + let mut federation_map = HashMap::with_capacity(federation_storage.federations.len()); + for (uuid, federation_index) in federation_storage.federations { let federation = FederationClient::new( - federation_item.0, - federation_item.1.federation_code.clone(), + uuid, + federation_index.federation_code, c.xprivkey, storage, c.network, @@ -2501,7 +2541,7 @@ mod tests { use crate::labels::{Contact, LabelStorage}; use crate::nostr::NostrKeySource; use crate::storage::{MemoryStorage, MutinyStorage}; - use crate::utils::parse_npub; + use crate::utils::{parse_npub, sleep}; use nostr::key::FromSkStr; use nostr::Keys; use wasm_bindgen_test::{wasm_bindgen_test as test, wasm_bindgen_test_configure}; @@ -2582,8 +2622,15 @@ mod tests { .await .expect("mutiny wallet should initialize"); + // let storage persist + sleep(1000).await; + assert_eq!(mw.node_manager.list_nodes().await.unwrap().len(), 1); + assert!(mw.node_manager.new_node().await.is_ok()); + // let storage persist + sleep(1000).await; + assert_eq!(mw.node_manager.list_nodes().await.unwrap().len(), 2); assert!(mw.stop().await.is_ok()); diff --git a/mutiny-core/src/node.rs b/mutiny-core/src/node.rs index 01ad9b7a8..d1eb33099 100644 --- a/mutiny-core/src/node.rs +++ b/mutiny-core/src/node.rs @@ -35,6 +35,8 @@ use bitcoin::{hashes::Hash, secp256k1::PublicKey, Network, OutPoint}; use core::time::Duration; use esplora_client::AsyncClient; use futures_util::lock::Mutex; +#[cfg(target_arch = "wasm32")] +use instant::Instant; use lightning::events::bump_transaction::{BumpTransactionEventHandler, Wallet}; use lightning::ln::channelmanager::ChannelDetails; use lightning::ln::PaymentSecret; @@ -78,6 +80,8 @@ use lightning_liquidity::{LiquidityClientConfig, LiquidityManager as LDKLSPLiqui #[cfg(test)] use mockall::predicate::*; use std::collections::HashMap; +#[cfg(not(target_arch = "wasm32"))] +use std::time::Instant; use std::{ str::FromStr, sync::{ @@ -290,6 +294,7 @@ impl NodeBuilder { } pub async fn build(self) -> Result, MutinyError> { + let node_start = Instant::now(); // check for all required parameters let uuid = self.uuid.as_ref().map_or_else( || Err(MutinyError::InvalidArgumentsError), @@ -382,7 +387,7 @@ impl NodeBuilder { let router: Arc = Arc::new(DefaultRouter::new( network_graph, logger.clone(), - keys_manager.clone().get_secure_random_bytes(), + keys_manager.get_secure_random_bytes(), scorer.clone(), scoring_params(), )); @@ -522,7 +527,9 @@ impl NodeBuilder { // sync to chain tip if read_channel_manager.is_restarting { - let mut chain_listener_channel_monitors = Vec::new(); + let start = Instant::now(); + let mut chain_listener_channel_monitors = + Vec::with_capacity(read_channel_manager.channel_monitors.len()); for (blockhash, channel_monitor) in read_channel_manager.channel_monitors.drain(..) { // Get channel monitor ready to sync channel_monitor.load_outputs_to_watch(&chain); @@ -549,6 +556,12 @@ impl NodeBuilder { .watch_channel(funding_outpoint, channel_monitor) .map_err(|_| MutinyError::ChainAccessFailed)?; } + + log_trace!( + logger, + "Syncing monitors to chain tip took {}ms", + start.elapsed().as_millis() + ); } // Before we start the background processor, retry previously failed @@ -569,38 +582,57 @@ impl NodeBuilder { }); if !retry_spendable_outputs.is_empty() { - log_info!( - logger, - "Retrying {} spendable outputs", - retry_spendable_outputs.len() - ); + let event_handler = event_handler.clone(); + let persister = persister.clone(); + let logger = logger.clone(); - match event_handler - .handle_spendable_outputs(&retry_spendable_outputs) - .await - { - Ok(_) => { - log_info!(logger, "Successfully retried spendable outputs"); - persister.clear_failed_spendable_outputs()?; - } - Err(_) => { - // retry them individually then only save failed ones - // if there was only one we don't need to retry - if retry_spendable_outputs.len() > 1 { - let mut failed = vec![]; - for o in retry_spendable_outputs { - if event_handler - .handle_spendable_outputs(&[o.clone()]) - .await - .is_err() - { - failed.push(o); - } + // We need to process our unhandled spendable outputs + // can do this in the background, no need to block on it + utils::spawn(async move { + let start = Instant::now(); + log_info!( + logger, + "Retrying {} spendable outputs", + retry_spendable_outputs.len() + ); + + match event_handler + .handle_spendable_outputs(&retry_spendable_outputs) + .await + { + Ok(_) => { + log_info!(logger, "Successfully retried spendable outputs"); + if let Err(e) = persister.clear_failed_spendable_outputs() { + log_warn!(logger, "Failed to clear failed spendable outputs: {e}"); } - persister.set_failed_spendable_outputs(failed)?; - }; + } + Err(_) => { + // retry them individually then only save failed ones + // if there was only one we don't need to retry + if retry_spendable_outputs.len() > 1 { + let mut failed = vec![]; + for o in retry_spendable_outputs { + if event_handler + .handle_spendable_outputs(&[o.clone()]) + .await + .is_err() + { + failed.push(o); + } + } + if let Err(e) = persister.set_failed_spendable_outputs(failed) { + log_warn!(logger, "Failed to set failed spendable outputs: {e}"); + } + }; + } } - } + + log_info!( + logger, + "Retrying spendable outputs took {}ms", + start.elapsed().as_millis() + ); + }); } // Check all existing channels against default configs. @@ -820,6 +852,12 @@ impl NodeBuilder { } }); + log_trace!( + logger, + "Node started, took {}ms", + node_start.elapsed().as_millis() + ); + Ok(Node { _uuid: uuid, stopped_components, diff --git a/mutiny-core/src/nodemanager.rs b/mutiny-core/src/nodemanager.rs index aab2e9e50..ebb300e69 100644 --- a/mutiny-core/src/nodemanager.rs +++ b/mutiny-core/src/nodemanager.rs @@ -1,3 +1,4 @@ +use crate::auth::MutinyAuthClient; use crate::event::HTLCStatus; use crate::labels::LabelStorage; use crate::logging::LOGGING_KEY; @@ -37,6 +38,8 @@ use bitcoin::{Address, Network, OutPoint, Transaction, Txid}; use core::time::Duration; use esplora_client::{AsyncClient, Builder}; use futures::{future::join_all, lock::Mutex}; +#[cfg(target_arch = "wasm32")] +use instant::Instant; use lightning::chain::Confirm; use lightning::events::ClosureReason; use lightning::ln::channelmanager::{ChannelDetails, PhantomRouteHints}; @@ -45,7 +48,7 @@ use lightning::ln::ChannelId; use lightning::routing::gossip::NodeId; use lightning::sign::{NodeSigner, Recipient}; use lightning::util::logger::*; -use lightning::{log_debug, log_error, log_info, log_warn}; +use lightning::{log_debug, log_error, log_info, log_trace, log_warn}; use lightning_invoice::Bolt11Invoice; use lightning_transaction_sync::EsploraSyncClient; use payjoin::Uri; @@ -56,6 +59,8 @@ use std::cmp::max; use std::io::Cursor; use std::str::FromStr; use std::sync::atomic::{AtomicBool, Ordering}; +#[cfg(not(target_arch = "wasm32"))] +use std::time::Instant; use std::{collections::HashMap, ops::Deref, sync::Arc}; use uuid::Uuid; @@ -319,10 +324,17 @@ impl NodeManagerBuilder { // Need to prevent other devices from running at the same time if !c.skip_device_lock { + let start = Instant::now(); + log_trace!(logger, "Checking device lock"); if let Some(lock) = self.storage.get_device_lock()? { log_info!(logger, "Current device lock: {lock:?}"); } self.storage.set_device_lock().await?; + log_trace!( + logger, + "Device lock set: took {}ms", + start.elapsed().as_millis() + ); } let storage_clone = self.storage.clone(); @@ -340,6 +352,9 @@ impl NodeManagerBuilder { } }); + let start = Instant::now(); + log_info!(logger, "Building node manager components"); + let esplora_server_url = get_esplora_url(c.network, c.user_esplora_url); let esplora = Builder::new(&esplora_server_url).build_async()?; let tx_sync = Arc::new(EsploraSyncClient::from_client( @@ -367,14 +382,8 @@ impl NodeManagerBuilder { let chain = Arc::new(MutinyChain::new(tx_sync, wallet.clone(), logger.clone())); - let (gossip_sync, scorer) = get_gossip_sync( - &self.storage, - c.scorer_url, - c.auth_client.clone(), - c.network, - logger.clone(), - ) - .await?; + let (gossip_sync, scorer) = + get_gossip_sync(&self.storage, c.network, logger.clone()).await?; let scorer = Arc::new(utils::Mutex::new(scorer)); @@ -388,6 +397,12 @@ impl NodeManagerBuilder { let node_storage = self.storage.get_nodes()?; + log_trace!( + logger, + "Node manager Components built: took {}ms", + start.elapsed().as_millis() + ); + let nodes = if c.safe_mode { // If safe mode is enabled, we don't start any nodes log_warn!(logger, "Safe mode enabled, not starting any nodes"); @@ -400,6 +415,9 @@ impl NodeManagerBuilder { .into_iter() .filter(|(_, n)| !n.is_archived()); + let start = Instant::now(); + log_debug!(logger, "Building nodes"); + let mut nodes_map = HashMap::new(); for node_item in unarchived_nodes { @@ -434,6 +452,11 @@ impl NodeManagerBuilder { nodes_map.insert(id, Arc::new(node)); } + log_trace!( + logger, + "Nodes built: took {}ms", + start.elapsed().as_millis() + ); // when we create the nodes we set the LSP if one is missing // we need to save it to local storage after startup in case @@ -443,16 +466,30 @@ impl NodeManagerBuilder { .map(|n| (n._uuid.clone(), n.node_index())) .collect(); + // insert updated nodes in background, isn't a huge deal if this fails, + // it is only for updating the LSP config log_info!(logger, "inserting updated nodes"); - - self.storage - .insert_nodes(&NodeStorage { - nodes: updated_nodes, - version: node_storage.version + 1, - }) - .await?; - - log_info!(logger, "inserted updated nodes"); + let version = node_storage.version + 1; + let storage = self.storage.clone(); + let logger_clone = logger.clone(); + spawn(async move { + let start = Instant::now(); + if let Err(e) = storage + .insert_nodes(&NodeStorage { + nodes: updated_nodes, + version, + }) + .await + { + log_error!(logger_clone, "Failed to insert updated nodes: {e}"); + } else { + log_info!( + logger_clone, + "inserted updated nodes, took {}ms", + start.elapsed().as_millis() + ); + } + }); Arc::new(RwLock::new(nodes_map)) }; @@ -479,6 +516,8 @@ impl NodeManagerBuilder { #[cfg(target_arch = "wasm32")] websocket_proxy_addr, user_rgs_url: c.user_rgs_url, + scorer_url: c.scorer_url, + auth_client: c.auth_client, esplora, lsp_config, logger, @@ -505,6 +544,8 @@ pub struct NodeManager { #[cfg(target_arch = "wasm32")] websocket_proxy_addr: String, user_rgs_url: Option, + scorer_url: Option, + auth_client: Option>, esplora: Arc, pub(crate) wallet: Arc>, gossip_sync: Arc, @@ -578,11 +619,6 @@ impl NodeManager { /// Creates a background process that will sync the wallet with the blockchain. /// This will also update the fee estimates every 10 minutes. pub fn start_sync(nm: Arc>) { - // If we are stopped, don't sync - if nm.stop.load(Ordering::Relaxed) { - return; - } - utils::spawn(async move { let mut synced = false; loop { @@ -597,6 +633,12 @@ impl NodeManager { } else { log_info!(nm.logger, "RGS Synced!"); } + + if let Err(e) = nm.sync_scorer().await { + log_error!(nm.logger, "Failed to sync scorer: {e}"); + } else { + log_info!(nm.logger, "Scorer Synced!"); + } } // we don't need to re-sync fees every time @@ -1165,6 +1207,39 @@ impl NodeManager { Ok(()) } + /// Downloads the latest score data from the server and replaces the current scorer. + /// Will be skipped if in safe mode. + async fn sync_scorer(&self) -> Result<(), MutinyError> { + // Skip syncing scorer if we are in safe mode. + if self.safe_mode { + log_info!(self.logger, "Skipping scorer sync in safe mode"); + return Ok(()); + } + + if let (Some(auth), Some(url)) = (self.auth_client.as_ref(), self.scorer_url.as_deref()) { + let scorer = get_remote_scorer( + auth, + url, + self.gossip_sync.network_graph().clone(), + self.logger.clone(), + ) + .await + .map_err(|e| { + log_error!(self.logger, "Failed to sync scorer: {e}"); + e + })?; + + // Replace the current scorer with the new one + let mut lock = self + .scorer + .try_lock() + .map_err(|_| MutinyError::WalletSyncError)?; + *lock = scorer; + } + + Ok(()) + } + /// Syncs the on-chain wallet and lightning wallet. /// This will update the on-chain wallet with any new /// transactions and update the lightning wallet with diff --git a/mutiny-core/src/test_utils.rs b/mutiny-core/src/test_utils.rs index e49ac7c7d..018d01a88 100644 --- a/mutiny-core/src/test_utils.rs +++ b/mutiny-core/src/test_utils.rs @@ -23,7 +23,7 @@ pub async fn create_vss_client() -> MutinyVssClient { // Test authenticate method match auth_client.authenticate().await { - Ok(_) => assert!(auth_client.is_authenticated().is_some()), + Ok(_) => assert!(auth_client.is_authenticated().await.is_some()), Err(e) => panic!("Authentication failed with error: {:?}", e), }; diff --git a/mutiny-core/src/utils.rs b/mutiny-core/src/utils.rs index 3924a94cf..063b73996 100644 --- a/mutiny-core/src/utils.rs +++ b/mutiny-core/src/utils.rs @@ -135,6 +135,13 @@ impl Mutex { lock: self.inner.borrow_mut(), }) } + + #[allow(clippy::result_unit_err)] + pub fn try_lock(&self) -> LockResult> { + Ok(MutexGuard { + lock: self.inner.try_borrow_mut().map_err(|_| ())?, + }) + } } impl<'a, T: 'a + ScoreLookUp + ScoreUpdate> LockableScore<'a> for Mutex { diff --git a/mutiny-wasm/src/indexed_db.rs b/mutiny-wasm/src/indexed_db.rs index 092af3721..149ce30f0 100644 --- a/mutiny-wasm/src/indexed_db.rs +++ b/mutiny-wasm/src/indexed_db.rs @@ -4,7 +4,7 @@ use bip39::Mnemonic; use futures::lock::Mutex; use gloo_utils::format::JsValueSerdeExt; use lightning::util::logger::Logger; -use lightning::{log_debug, log_error}; +use lightning::{log_debug, log_error, log_trace}; use log::error; use mutiny_core::storage::*; use mutiny_core::vss::*; @@ -260,6 +260,7 @@ impl IndexedDbStorage { })? }; + let start = instant::Instant::now(); // use a memory storage to handle encryption and decryption let map = MemoryStorage::new(password, cipher, None); @@ -283,6 +284,11 @@ impl IndexedDbStorage { let json: Value = value.into_serde()?; map.set(vec![(key, json)])?; } + log_trace!( + logger, + "Reading browser storage took {}ms", + start.elapsed().as_millis() + ); match vss { None => { @@ -290,26 +296,29 @@ impl IndexedDbStorage { Ok(final_map.clone()) } Some(vss) => { - log_debug!(logger, "Reading from vss"); + log_trace!(logger, "Reading from vss"); + let start = instant::Instant::now(); let keys = vss.list_key_versions(None).await?; - let mut futs = vec![]; + let mut futs = Vec::with_capacity(keys.len()); for kv in keys { futs.push(Self::handle_vss_key(kv, vss, &map, logger)); } - let results = futures::future::join_all(futs).await; - let mut items_vector = Vec::new(); - for result in results { - if let Some((key, value)) = result? { - // save to memory and batch the write to local storage - map.set_data(key.clone(), value.clone(), None)?; - items_vector.push((key, value)); - } + let results = futures::future::try_join_all(futs).await?; + + let mut items_vector = Vec::with_capacity(results.len()); + for (key, value) in results.into_iter().flatten() { + // save to memory and batch the write to local storage + map.set_data(key.clone(), value.clone(), None)?; + items_vector.push((key, value)); } if !items_vector.is_empty() { // write them so we don't have to pull them down again Self::save_to_indexed_db(indexed_db, &items_vector).await?; } let final_map = map.memory.read().unwrap(); + + log_trace!(logger, "Reading VSS took {}ms", start.elapsed().as_millis()); + Ok(final_map.clone()) } } diff --git a/mutiny-wasm/src/lib.rs b/mutiny-wasm/src/lib.rs index 1e9995eb3..912d533ef 100644 --- a/mutiny-wasm/src/lib.rs +++ b/mutiny-wasm/src/lib.rs @@ -25,7 +25,7 @@ use bitcoin::{Address, Network, OutPoint, Transaction, Txid}; use fedimint_core::{api::InviteCode, config::FederationId}; use futures::lock::Mutex; use gloo_utils::format::JsValueSerdeExt; -use lightning::{log_error, routing::gossip::NodeId, util::logger::Logger}; +use lightning::{log_error, log_info, log_warn, routing::gossip::NodeId, util::logger::Logger}; use lightning_invoice::Bolt11Invoice; use lnurl::lightning_address::LightningAddress; use lnurl::lnurl::LnUrl; @@ -35,7 +35,7 @@ use mutiny_core::nostr::nip49::NIP49URI; use mutiny_core::nostr::nwc::{BudgetedSpendingConditions, NwcProfileTag, SpendingConditions}; use mutiny_core::nostr::NostrKeySource; use mutiny_core::storage::{DeviceLock, MutinyStorage, DEVICE_LOCK_KEY}; -use mutiny_core::utils::{now, parse_npub, parse_npub_or_nip05, sleep}; +use mutiny_core::utils::{now, parse_npub, parse_npub_or_nip05, sleep, spawn}; use mutiny_core::vss::MutinyVssClient; use mutiny_core::{encrypt::encryption_key_from_pass, InvoiceHandler, MutinyWalletConfigBuilder}; use mutiny_core::{labels::Contact, MutinyWalletBuilder}; @@ -105,6 +105,7 @@ impl MutinyWallet { nip_07_key: Option, primal_url: Option, ) -> Result { + let start = instant::Instant::now(); // if both are set throw an error // todo default to nsec if both are for same key? if nsec_override.is_some() && nip_07_key.is_some() { @@ -143,7 +144,14 @@ impl MutinyWallet { ) .await { - Ok(m) => Ok(m), + Ok(m) => { + log_info!( + m.inner.logger, + "Wallet startup took {}ms", + start.elapsed().as_millis() + ); + Ok(m) + } Err(e) => { // mark uninitialized because we failed to startup *init = false; @@ -215,6 +223,19 @@ impl MutinyWallet { auth_url, )); + // immediately start fetching JWT + let auth = auth_client.clone(); + let logger_clone = logger.clone(); + spawn(async move { + // if this errors, it's okay, we'll call it again when we fetch vss + if let Err(e) = auth.authenticate().await { + log_warn!( + logger_clone, + "Failed to authenticate on startup, will retry on next call: {e}" + ); + } + }); + let vss = storage_url.map(|url| { Arc::new(MutinyVssClient::new_authenticated( auth_client.clone(),