From c45b8ab98d9d851d2d074820b2e66a3033219ca7 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Sat, 3 May 2025 16:28:51 +0100 Subject: [PATCH 01/24] feat: add retry mechanism to rate-limited requests in Photon indexer Replaced `rate_limited_request` with `rate_limited_request_with_retry` to include a retry mechanism for handling transient errors. --- sdk-libs/client/src/indexer/photon_indexer.rs | 70 +++++++++---------- 1 file changed, 35 insertions(+), 35 deletions(-) diff --git a/sdk-libs/client/src/indexer/photon_indexer.rs b/sdk-libs/client/src/indexer/photon_indexer.rs index 722a880d17..02c931be31 100644 --- a/sdk-libs/client/src/indexer/photon_indexer.rs +++ b/sdk-libs/client/src/indexer/photon_indexer.rs @@ -1,4 +1,4 @@ -use std::{fmt::Debug, str::FromStr, time::Duration}; +use std::{fmt::Debug, str::FromStr}; use async_trait::async_trait; use light_compressed_account::compressed_account::{ @@ -94,12 +94,12 @@ impl PhotonIndexer { loop { attempts += 1; - if let Some(limiter) = &self.rate_limiter { + if let Some(limiter) = &self.rate_limiter { debug!( "Attempt {}/{}: Acquiring rate limiter", attempts, max_retries ); - limiter.acquire_with_wait().await; + limiter.acquire_with_wait().await; debug!( "Attempt {}/{}: Rate limiter acquired", attempts, max_retries @@ -549,10 +549,10 @@ impl Indexer for PhotonIndexer { self.rate_limited_request_with_retry(|| async { let request = photon_api::models::GetCompressedTokenAccountsByOwnerPostRequest { params: Box::new(GetCompressedTokenAccountsByOwnerPostRequestParams { - owner: owner.to_string(), - mint: mint.map(|x| x.to_string()), - cursor: None, - limit: None, + owner: owner.to_string(), + mint: mint.map(|x| x.to_string()), + cursor: None, + limit: None, }), ..Default::default() }; @@ -662,10 +662,10 @@ impl Indexer for PhotonIndexer { self.rate_limited_request_with_retry(|| async { let request = photon_api::models::GetCompressedTokenBalancesByOwnerPostRequest { params: Box::new(GetCompressedTokenAccountsByOwnerPostRequestParams { - owner: owner.to_string(), - mint: mint.map(|x| x.to_string()), - cursor: None, - limit: None, + owner: owner.to_string(), + mint: mint.map(|x| x.to_string()), + cursor: None, + limit: None, }), ..Default::default() }; @@ -865,32 +865,32 @@ impl Indexer for PhotonIndexer { new_addresses_with_trees: Vec, ) -> Result { self.rate_limited_request_with_retry(|| async { - let request = photon_api::models::GetValidityProofV2PostRequest { - params: Box::new(photon_api::models::GetValidityProofPostRequestParams { - hashes: Some(hashes.iter().map(|x| x.to_base58()).collect()), - new_addresses_with_trees: Some( - new_addresses_with_trees - .iter() - .map(|x| photon_api::models::AddressWithTree { - address: x.address.to_base58(), - tree: x.tree.to_string(), - }) - .collect(), - ), - }), - ..Default::default() - }; + let request = photon_api::models::GetValidityProofV2PostRequest { + params: Box::new(photon_api::models::GetValidityProofPostRequestParams { + hashes: Some(hashes.iter().map(|x| x.to_base58()).collect()), + new_addresses_with_trees: Some( + new_addresses_with_trees + .iter() + .map(|x| photon_api::models::AddressWithTree { + address: x.address.to_base58(), + tree: x.tree.to_string(), + }) + .collect(), + ), + }), + ..Default::default() + }; - let result = photon_api::apis::default_api::get_validity_proof_v2_post( - &self.configuration, - request, - ) - .await?; + let result = photon_api::apis::default_api::get_validity_proof_v2_post( + &self.configuration, + request, + ) + .await?; - let result = Self::extract_result("get_validity_proof_v2", result.result)?; - Ok(*result.value) - }) - .await + let result = Self::extract_result("get_validity_proof_v2", result.result)?; + Ok(*result.value) + }) + .await } async fn get_indexer_slot(&self, _r: &mut R) -> Result { From 75baade07673f6c983bdd9ebfa6fc09115658708 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Sat, 3 May 2025 18:14:43 +0100 Subject: [PATCH 02/24] format --- sdk-libs/client/src/indexer/photon_indexer.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/sdk-libs/client/src/indexer/photon_indexer.rs b/sdk-libs/client/src/indexer/photon_indexer.rs index 02c931be31..2df0938fea 100644 --- a/sdk-libs/client/src/indexer/photon_indexer.rs +++ b/sdk-libs/client/src/indexer/photon_indexer.rs @@ -1,5 +1,5 @@ use std::{fmt::Debug, str::FromStr}; - +use std::time::Duration; use async_trait::async_trait; use light_compressed_account::compressed_account::{ CompressedAccount, CompressedAccountData, CompressedAccountWithMerkleContext, MerkleContext, @@ -94,12 +94,12 @@ impl PhotonIndexer { loop { attempts += 1; - if let Some(limiter) = &self.rate_limiter { + if let Some(limiter) = &self.rate_limiter { debug!( "Attempt {}/{}: Acquiring rate limiter", attempts, max_retries ); - limiter.acquire_with_wait().await; + limiter.acquire_with_wait().await; debug!( "Attempt {}/{}: Rate limiter acquired", attempts, max_retries From 582872a7964e06227cbe7874ff53acfbd14e5a4f Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Sat, 3 May 2025 23:27:16 +0100 Subject: [PATCH 03/24] Reduced initial retry delay to 100ms and capped exponential backoff at 4000ms to improve responsiveness and mitigate excessive delays. --- sdk-libs/client/src/indexer/photon_indexer.rs | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/sdk-libs/client/src/indexer/photon_indexer.rs b/sdk-libs/client/src/indexer/photon_indexer.rs index 2df0938fea..bc080ee0d2 100644 --- a/sdk-libs/client/src/indexer/photon_indexer.rs +++ b/sdk-libs/client/src/indexer/photon_indexer.rs @@ -549,10 +549,10 @@ impl Indexer for PhotonIndexer { self.rate_limited_request_with_retry(|| async { let request = photon_api::models::GetCompressedTokenAccountsByOwnerPostRequest { params: Box::new(GetCompressedTokenAccountsByOwnerPostRequestParams { - owner: owner.to_string(), - mint: mint.map(|x| x.to_string()), - cursor: None, - limit: None, + owner: owner.to_string(), + mint: mint.map(|x| x.to_string()), + cursor: None, + limit: None, }), ..Default::default() }; @@ -662,10 +662,10 @@ impl Indexer for PhotonIndexer { self.rate_limited_request_with_retry(|| async { let request = photon_api::models::GetCompressedTokenBalancesByOwnerPostRequest { params: Box::new(GetCompressedTokenAccountsByOwnerPostRequestParams { - owner: owner.to_string(), - mint: mint.map(|x| x.to_string()), - cursor: None, - limit: None, + owner: owner.to_string(), + mint: mint.map(|x| x.to_string()), + cursor: None, + limit: None, }), ..Default::default() }; From a08fb27dde76892ec7fd75905442546c02f041e3 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Sat, 3 May 2025 16:29:59 +0100 Subject: [PATCH 04/24] refactor: transaction sending --- Cargo.lock | 1 + forester-utils/src/forester_epoch.rs | 6 + forester/src/epoch_manager.rs | 383 +++++++++++--------- forester/src/forester_status.rs | 256 ++++++++++++- forester/src/send_transaction.rs | 292 +++++++++------ sdk-libs/client/Cargo.toml | 1 + sdk-libs/photon-api/src/apis/default_api.rs | 1 + 7 files changed, 656 insertions(+), 284 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index d068384c3d..66dd51996a 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -3345,6 +3345,7 @@ dependencies = [ "light-prover-client", "light-sdk", "light-test-utils", + "log", "num-bigint 0.4.6", "num-traits", "photon-api", diff --git a/forester-utils/src/forester_epoch.rs b/forester-utils/src/forester_epoch.rs index 4408a37f39..2320e45ef1 100644 --- a/forester-utils/src/forester_epoch.rs +++ b/forester-utils/src/forester_epoch.rs @@ -211,6 +211,12 @@ pub struct Phase { pub end: u64, } +impl Phase { + pub fn length(&self) -> u64 { + self.end - self.start + } +} + pub fn get_epoch_phases(protocol_config: &ProtocolConfig, epoch: u64) -> EpochPhases { let epoch_start_slot = protocol_config .genesis_slot diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 960c1b8658..85403c9a4b 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -24,6 +24,7 @@ use light_registry::{ EpochPda, ForesterEpochPda, }; use solana_program::{instruction::InstructionError, pubkey::Pubkey}; +use solana_program::native_token::LAMPORTS_PER_SOL; use solana_sdk::{signature::Signer, transaction::TransactionError}; use tokio::{ sync::{broadcast, broadcast::error::RecvError, mpsc, oneshot, Mutex}, @@ -188,20 +189,27 @@ impl + IndexerType> EpochManager { } async fn check_sol_balance_periodically(self: Arc) -> Result<()> { - let interval = Duration::from_secs(60); - let mut interval_timer = tokio::time::interval(interval); + let interval_duration = Duration::from_secs(300); + let mut interval = tokio::time::interval(interval_duration); loop { - interval_timer.tick().await; - let mut rpc = self.rpc_pool.get_connection().await?; - let balance = rpc.get_balance(&self.config.payer_keypair.pubkey()).await?; - let balance_in_sol = balance as f64 / 1e9; - update_forester_sol_balance( - &self.config.payer_keypair.pubkey().to_string(), - balance_in_sol, - ); - info!("Current SOL balance: {} SOL", balance_in_sol); - tokio::task::yield_now().await; + interval.tick().await; + match self.rpc_pool.get_connection().await { + Ok(mut rpc) => { + match rpc.get_balance(&self.config.payer_keypair.pubkey()).await { + Ok(balance) => { + let balance_in_sol = balance as f64 / (LAMPORTS_PER_SOL as f64); + update_forester_sol_balance( + &self.config.payer_keypair.pubkey().to_string(), + balance_in_sol, + ); + debug!("Current SOL balance: {} SOL", balance_in_sol); + }, + Err(e) => error!("Failed to get balance: {:?}", e), + } + }, + Err(e) => error!("Failed to get RPC connection for balance check: {:?}", e), + } } } @@ -670,8 +678,8 @@ impl + IndexerType> EpochManager { epoch_info: &ForesterEpochInfo, ) -> Result { info!("Waiting for active phase"); - let mut rpc = self.rpc_pool.get_connection().await?; + let mut rpc = self.rpc_pool.get_connection().await?; let active_phase_start_slot = epoch_info.epoch.phases.active.start; wait_until_slot_reached(&mut *rpc, &self.slot_tracker, active_phase_start_slot).await?; @@ -791,8 +799,6 @@ impl + IndexerType> EpochManager { Ok(()) } - // Sync estimated slot before creating threads. - // Threads rely on the estimated slot. async fn sync_slot(&self) -> Result { let mut rpc = self.rpc_pool.get_connection().await?; let current_slot = rpc.get_slot().await?; @@ -821,196 +827,226 @@ impl + IndexerType> EpochManager { estimated_slot, epoch_info.phases.active.end ); - while estimated_slot < epoch_info.phases.active.end { - // search for next eligible slot + 'outer: while estimated_slot < epoch_info.phases.active.end { + let index_and_forester_slot = tree .slots .iter() .enumerate() .find(|(_, slot)| slot.is_some()); - if let Some((index, forester_slot)) = index_and_forester_slot { + if let Some((slot_index, forester_slot)) = index_and_forester_slot { let forester_slot = forester_slot.as_ref().unwrap().clone(); - tree.slots.remove(index); - - info!("Found eligible slot: {:?}", forester_slot); + info!( + "Found eligible slot: {:?}. Target start: {}, Target end: {}", + forester_slot.slot, forester_slot.start_solana_slot, forester_slot.end_solana_slot + ); - let mut rpc = self.rpc_pool.get_connection().await?; + let context_str = format!("process_queue (wait_until_slot_reached), tree: {}", tree.tree_accounts.merkle_tree); + debug!(context = %context_str, "Attempting to get RPC connection for wait..."); + let rpc_result = self.rpc_pool.get_connection().await; + match rpc_result { + Ok(_) => { debug!(context = %context_str, "Successfully got RPC connection for wait."); } + Err(ref e) => { error!(context = %context_str, "Failed to get RPC connection for wait: {:?}", e); } + } + let mut rpc = rpc_result?; info!( - "Current solana slot: {}, waiting for slot {}", - estimated_slot, forester_slot.start_solana_slot - ); + "Current estimated solana slot: {}, waiting for slot {} to begin", + self.slot_tracker.estimated_current_slot(), + forester_slot.start_solana_slot + ); - wait_until_slot_reached( + if let Err(e) = wait_until_slot_reached( &mut *rpc, &self.slot_tracker, forester_slot.start_solana_slot, ) - .await?; + .await { + error!("Error waiting for slot {} to start: {:?}. Skipping slot.", forester_slot.start_solana_slot, e); + tree.slots[slot_index] = None; + continue 'outer; + } + info!("Reached start slot {}. Beginning processing window until slot {}.", forester_slot.start_solana_slot, forester_slot.end_solana_slot); + 'inner: loop { + estimated_slot = self.slot_tracker.estimated_current_slot(); + if estimated_slot >= forester_slot.end_solana_slot { + info!( + "Ending processing for slot {:?} ({}) due to reaching/exceeding end slot {}", + forester_slot.slot, forester_slot.start_solana_slot, forester_slot.end_solana_slot + ); + break 'inner; + } - // light slot length in s - let light_slot_timeout = { - let slot_length_u32 = u32::try_from(epoch_pda.protocol_config.slot_length) - .map_err(|_| ConfigurationError::SlotLengthOverflow { - value: epoch_pda.protocol_config.slot_length, - })?; - - let duration = slot_duration(); - duration.checked_mul(slot_length_u32).ok_or( - ConfigurationError::TimeoutCalculationOverflow { - slot_duration: duration, - slot_length: slot_length_u32, - }, - )? - }; + debug!( + "Inner loop iteration for slot {:?}. Current estimated: {}, End: {}", + forester_slot.slot, estimated_slot, forester_slot.end_solana_slot + ); - if tree.tree_accounts.tree_type == TreeType::StateV2 - || tree.tree_accounts.tree_type == TreeType::AddressV2 - { - let batch_context = BatchContext { - rpc_pool: self.rpc_pool.clone(), - indexer: self.indexer.clone(), - authority: self.config.payer_keypair.insecure_clone(), - derivation: self.config.derivation_pubkey, - epoch: epoch_info.epoch, - merkle_tree: tree.tree_accounts.merkle_tree, - output_queue: tree.tree_accounts.queue, - ixs_per_tx: self.config.transaction_config.batch_ixs_per_tx, - }; - - let start_time = Instant::now(); - - match process_batched_operations(batch_context, tree.tree_accounts.tree_type) - .await + let mut items_processed_this_iteration = 0; + let mut iteration_failed = false; + let processing_start_time = Instant::now(); + + if tree.tree_accounts.tree_type == TreeType::StateV1 + || tree.tree_accounts.tree_type == TreeType::AddressV1 { - Ok(processed_count) => { - info!( - "Processed {} operations for tree type {:?}", - processed_count, tree.tree_accounts.tree_type - ); - queue_metric_update( - epoch_info.epoch, - processed_count, - start_time.elapsed(), - ) - .await; - self.increment_processed_items_count(epoch_info.epoch, processed_count) - .await; - } - Err(e) => { - error!( - "Failed to process batched operations for tree {:?}: {:?}", - tree.tree_accounts.merkle_tree, e - ); - return Err(e.into()); - } - } - } else { - let batched_tx_config = SendBatchedTransactionsConfig { - num_batches: 2, - build_transaction_batch_config: BuildTransactionBatchConfig { - batch_size: 50, - compute_unit_price: Some(10_000), // Is dynamic. Sets max. - compute_unit_limit: Some(180_000), - enable_priority_fees: self - .config - .transaction_config - .enable_priority_fees, - }, - queue_config: self.config.queue_config, - retry_config: RetryConfig { - timeout: light_slot_timeout, - ..self.config.retry_config - }, + let transaction_timeout_buffer = Duration::from_secs(60); - light_slot_length: epoch_pda.protocol_config.slot_length, - }; - - let transaction_builder = EpochManagerTransactions { - indexer: self.indexer.clone(), // TODO: remove clone - epoch: epoch_info.epoch, - phantom: std::marker::PhantomData::, - }; - - info!("Sending transactions..."); - let start_time = Instant::now(); - let batch_tx_future = send_batched_transactions( - &self.config.payer_keypair, - &self.config.derivation_pubkey, - self.rpc_pool.clone(), - &batched_tx_config, // TODO: define config in epoch manager - tree.tree_accounts, - &transaction_builder, - ); + let remaining_time_timeout = calculate_remaining_time_or_default( + estimated_slot, + forester_slot.end_solana_slot, + transaction_timeout_buffer, + ); + + trace!("Calculated remaining time timeout for send_batched_transactions: {:?}", remaining_time_timeout); + + let batched_tx_config = SendBatchedTransactionsConfig { + num_batches: 1, + build_transaction_batch_config: BuildTransactionBatchConfig { + batch_size: 1, + compute_unit_price: Some(10_000), + compute_unit_limit: Some(300_000), + enable_priority_fees: self + .config + .transaction_config + .enable_priority_fees, + }, + queue_config: self.config.queue_config, + retry_config: RetryConfig { + timeout: remaining_time_timeout, + ..self.config.retry_config + }, + light_slot_length: epoch_pda.protocol_config.slot_length, + }; - // Check whether the tree is ready for rollover once per slot. - let future = self.rollover_if_needed(&tree.tree_accounts); + let transaction_builder = EpochManagerTransactions { + indexer: self.indexer.clone(), + epoch: epoch_info.epoch, + phantom: std::marker::PhantomData::, + }; - // Wait for both operations to complete - let (num_tx_sent, rollover_result) = tokio::join!(batch_tx_future, future); - if let Err(e) = rollover_result { - error!("Error during rollover check: {:?}", e); - } + info!("Attempting to send transactions within slot {:?}", forester_slot.slot); + match send_batched_transactions( + &self.config.payer_keypair, + &self.config.derivation_pubkey, + self.rpc_pool.clone(), + &batched_tx_config, + tree.tree_accounts, + &transaction_builder, + ) + .await + { + Ok(num_sent) => { + if num_sent > 0 { + trace!("{} transactions sent in this iteration", num_sent); + let iteration_duration = processing_start_time.elapsed(); + queue_metric_update(epoch_info.epoch, num_sent, iteration_duration).await; + self.increment_processed_items_count(epoch_info.epoch, num_sent).await; + items_processed_this_iteration = num_sent; + + trace!("Checking for rollover readiness after processing batch..."); + if let Err(e) = self.rollover_if_needed(&tree.tree_accounts).await { + error!("Rollover check failed during slot processing: {:?}", e); + } else { + trace!("Rollover check completed."); + } - match num_tx_sent { - Ok(num_tx_sent) => { - trace!("{} transactions sent", num_tx_sent); - let chunk_duration = start_time.elapsed(); - queue_metric_update(epoch_info.epoch, num_tx_sent, chunk_duration) - .await; - self.increment_processed_items_count(epoch_info.epoch, num_tx_sent) - .await; + } else { + info!("send_batched_transactions processed 0 items. Queue likely empty for this attempt."); + } + } + Err(e) => { + error!("Failed to send transactions within slot {:?}: {:?}", forester_slot.slot, e); + iteration_failed = true; + } } - Err(e) => { - error!("Failed to send transactions: {:?}", e); - if let Some(client_error) = - e.downcast_ref::().and_then(|rpc_err| { - if let RpcError::ClientError(client_err) = rpc_err { - Some(client_err) + } + else if tree.tree_accounts.tree_type == TreeType::StateV2 + || tree.tree_accounts.tree_type == TreeType::AddressV2 + { + let batch_context = BatchContext { + rpc_pool: self.rpc_pool.clone(), + indexer: self.indexer.clone(), + authority: self.config.payer_keypair.insecure_clone(), + derivation: self.config.derivation_pubkey, + epoch: epoch_info.epoch, + merkle_tree: tree.tree_accounts.merkle_tree, + output_queue: tree.tree_accounts.queue, + ixs_per_tx: self.config.transaction_config.batch_ixs_per_tx, + }; + match process_batched_operations(batch_context, tree.tree_accounts.tree_type).await { + Ok(processed_count) => { + if processed_count > 0 { + info!( + "Processed {} V2 operations for tree type {:?}", + processed_count, tree.tree_accounts.tree_type + ); + let iteration_duration = processing_start_time.elapsed(); + queue_metric_update(epoch_info.epoch, processed_count, iteration_duration).await; + self.increment_processed_items_count(epoch_info.epoch, processed_count).await; + items_processed_this_iteration = processed_count; + + trace!("Checking for V2 rollover readiness after processing batch..."); + if let Err(e) = self.rollover_if_needed(&tree.tree_accounts).await { + error!("V2 Rollover check failed during slot processing: {:?}", e); } else { - None - } - }) - { - if let Some(tx_error) = client_error.get_transaction_error() { - error!("Transaction error details: {:?}", tx_error); - if let TransactionError::InstructionError( - idx, - instruction_error, - ) = tx_error - { - error!( - "Failed at instruction {}: {:?}", - idx, instruction_error - ); - if let InstructionError::Custom(code) = instruction_error { - error!("Custom error code: 0x{:x} ({})", code, code); - } + trace!("V2 Rollover check completed."); } + } else { + info!("process_batched_operations processed 0 items. Queue likely empty for this attempt."); } } - warn!("Continuing despite transaction send failure"); + Err(e) => { + error!( + "Failed to process V2 batched operations for tree {:?} within slot {:?}: {:?}", + tree.tree_accounts.merkle_tree, forester_slot.slot, e + ); + iteration_failed = true; + } } + } else { + warn!("Unsupported tree type encountered in process_queue: {:?}", tree.tree_accounts.tree_type); + iteration_failed = true; + } + + if iteration_failed { + error!("Exiting inner loop for slot {:?} due to processing error.", forester_slot.slot); + break 'inner; + } + + push_metrics(&self.config.external_services.pushgateway_url).await?; + + if items_processed_this_iteration == 0 { + let queue_check_interval = Duration::from_secs(2); + debug!("No items processed, sleeping for {:?} before re-checking queue/time within slot.", queue_check_interval); + sleep(queue_check_interval).await; + } else { + trace!("Yielding after processing items within slot."); + tokio::task::yield_now().await; + } + + if self.slot_tracker.estimated_current_slot() >= forester_slot.end_solana_slot { + info!("Exiting inner loop for slot {:?} after sleep/yield time check.", forester_slot.slot); + break 'inner; } } + + info!( + "Finished processing window for slot {:?} (Started: {}, Ended: {}). Marking as processed.", + forester_slot.slot, forester_slot.start_solana_slot, forester_slot.end_solana_slot + ); + tree.slots[slot_index] = None; } else { - info!("No eligible slot found"); - break; + info!("No further eligible slots found in schedule for this epoch and tree."); + break 'outer; } - - push_metrics(&self.config.external_services.pushgateway_url).await?; - - // Yield to allow other tasks to run tokio::task::yield_now().await; - estimated_slot = self.slot_tracker.estimated_current_slot(); - info!( - "Estimated slot: {}, epoch end: {}", - estimated_slot, epoch_info.phases.active.end - ); } + + info!("Exiting process_queue for epoch {}, tree {}", epoch_info.epoch, tree.tree_accounts.merkle_tree); + Ok(()) } @@ -1176,6 +1212,15 @@ impl + IndexerType> EpochManager { } } +fn calculate_remaining_time_or_default(current_slot: u64, end_slot: u64, buffer_duration: Duration) -> Duration { + if current_slot >= end_slot { + return Duration::ZERO; + } + let slots_remaining = end_slot - current_slot; + let base_remaining_duration = slot_duration().checked_mul(slots_remaining as u32).unwrap_or_default(); + base_remaining_duration.checked_sub(buffer_duration).unwrap_or_else(|| Duration::ZERO) +} + #[instrument( level = "info", skip(config, protocol_config, rpc_pool, indexer, shutdown, work_report_sender, slot_tracker), diff --git a/forester/src/forester_status.rs b/forester/src/forester_status.rs index 7acec1c687..7919e2bd13 100644 --- a/forester/src/forester_status.rs +++ b/forester/src/forester_status.rs @@ -1,13 +1,5 @@ use std::sync::Arc; -use anchor_lang::{AccountDeserialize, Discriminator}; -use itertools::Itertools; -use light_client::rpc::{RpcConnection, SolanaRpcConnection}; -use light_compressed_account::TreeType; -use light_registry::{protocol_config::state::ProtocolConfigPda, EpochPda, ForesterEpochPda}; -use solana_sdk::{account::ReadableAccount, commitment_config::CommitmentConfig}; -use tracing::{debug, warn}; - use crate::{ cli::StatusArgs, metrics::{push_metrics, register_metrics, update_registered_foresters}, @@ -16,6 +8,16 @@ use crate::{ tree_data_sync::fetch_trees, ForesterConfig, }; +use anchor_lang::{AccountDeserialize, Discriminator}; +use forester_utils::forester_epoch::get_epoch_phases; +use itertools::Itertools; +use light_client::rpc::{RpcConnection, SolanaRpcConnection}; +use light_compressed_account::TreeType; +use light_registry::{protocol_config::state::ProtocolConfigPda, EpochPda, ForesterEpochPda}; +use solana_program::clock::Slot; +use solana_program::pubkey::Pubkey; +use solana_sdk::{account::ReadableAccount, commitment_config::CommitmentConfig}; +use tracing::{debug, warn}; pub async fn fetch_forester_status(args: &StatusArgs) { let commitment_config = CommitmentConfig::confirmed(); @@ -56,6 +58,9 @@ pub async fn fetch_forester_status(args: &StatusArgs) { forester_epoch_pdas.sort_by(|a, b| a.epoch.cmp(&b.epoch)); epoch_pdas.sort_by(|a, b| a.epoch.cmp(&b.epoch)); let slot = client.get_slot().expect("Failed to fetch slot."); + + println!("Current Solana Slot: {}", slot); + let current_active_epoch = protocol_config_pdas[0] .config .get_current_active_epoch(slot) @@ -159,6 +164,7 @@ pub async fn fetch_forester_status(args: &StatusArgs) { if args.protocol_config { println!("protocol config: {:?}", protocol_config_pdas[0]); } + let config = Arc::new(ForesterConfig::new_for_status(args).unwrap()); if config.general_config.enable_metrics { @@ -188,9 +194,243 @@ pub async fn fetch_forester_status(args: &StatusArgs) { tree_info.next_index, tree_info.threshold ); + + if args.full { + println!("Checking Forester Assignment for {}...", tree.merkle_tree); + + let active_epoch_foresters: Vec = forester_epoch_pdas + .iter() + .filter(|item| item.epoch == current_active_epoch) + .cloned() + .collect(); + + let current_epoch_pda_entry = epoch_pdas + .iter() + .find(|pda| pda.epoch == current_active_epoch); + + let protocol_config = protocol_config_pdas[0].clone(); + + print_tree_schedule_by_forester( + slot, + current_active_epoch, + active_epoch_foresters, + tree.merkle_tree, + tree.queue, + current_epoch_pda_entry, + &protocol_config, + ); + } } push_metrics(&config.external_services.pushgateway_url) .await .unwrap(); } + +fn print_tree_schedule_by_forester( + slot: Slot, + current_active_epoch: u64, + active_epoch_foresters: Vec, + tree: Pubkey, + queue: Pubkey, + current_epoch_pda_entry: Option<&EpochPda>, + protocol_config: &ProtocolConfigPda, +) { + if let Some(_current_epoch_pda) = current_epoch_pda_entry { + if active_epoch_foresters.is_empty() { + println!( + "ERROR: No foresters registered for tree {} in active epoch {}", + tree, current_active_epoch + ); + } else { + let total_epoch_weight = match active_epoch_foresters[0].total_epoch_weight { + Some(w) if w > 0 => w, + _ => { + println!( + "ERROR: Registration not finalized (total_epoch_weight is None or 0) for epoch {}. Cannot check assignments.", + current_active_epoch + ); + 0 + } + }; + + if total_epoch_weight > 0 { + let epoch_phases = get_epoch_phases(&protocol_config.config, current_active_epoch); + + if slot >= epoch_phases.active.start && slot < epoch_phases.active.end { + if protocol_config.config.slot_length > 0 { + let current_light_slot_index = + (slot - epoch_phases.active.start) / protocol_config.config.slot_length; + let start_solana_slot_of_current_light_slot = epoch_phases.active.start + + current_light_slot_index * protocol_config.config.slot_length; + let end_solana_slot_of_current_light_slot = + start_solana_slot_of_current_light_slot + + protocol_config.config.slot_length; + + let slots_remaining_in_light_slot = + end_solana_slot_of_current_light_slot.saturating_sub(slot); + let time_remaining_secs = slots_remaining_in_light_slot as f64 * 0.460; + + println!( + "Current Light Slot Index: {} (Approx. {:.2}s remaining)", + current_light_slot_index, time_remaining_secs + ); + } else { + println!("WARN: Cannot calculate light slot info because ProtocolConfig slot_length is zero."); + } + } else { + println!( + "Info: Not currently within the active phase of epoch {}.", + current_active_epoch + ); + } + + let num_light_slots = if protocol_config.config.slot_length > 0 { + epoch_phases.active.length() / protocol_config.config.slot_length + } else { + println!( + "ERROR: ProtocolConfig slot_length is zero. Cannot calculate light slots." + ); + 0 + }; + + let mut all_slots_checked = true; + let mut first_missing_slot = -1i64; + + println!( + "Checking assignment for {} light slots (Epoch {}, Tree {}, Queue {})...", + num_light_slots, current_active_epoch, tree, queue + ); + + for i in 0..num_light_slots { + let current_light_slot = i; + + let eligible_forester_slot_index = + match ForesterEpochPda::get_eligible_forester_index( + current_light_slot, + &queue, + total_epoch_weight, + current_active_epoch, + ) { + Ok(idx) => idx, + Err(e) => { + println!( + "ERROR calculating eligible index for light slot {}: {:?}", + i, e + ); + all_slots_checked = false; + if first_missing_slot == -1 { + first_missing_slot = i as i64; + } + continue; + } + }; + + let is_any_forester_eligible = active_epoch_foresters + .iter() + .any(|pda| pda.is_eligible(eligible_forester_slot_index)); + + if !is_any_forester_eligible { + all_slots_checked = false; + if first_missing_slot == -1 { + first_missing_slot = i as i64; + } + warn!( + "Check WARNING: Tree {} is missing forester assignment for light slot index {} (eligible index: {}) in epoch {}.", + tree, i, eligible_forester_slot_index, current_active_epoch + ); + } + } + + if all_slots_checked { + println!( + "Check PASSED: Tree {} has a forester assigned for all {} light slots in epoch {}.", + tree, num_light_slots, current_active_epoch + ); + + let current_light_slot_index = if slot >= epoch_phases.active.start + && slot < epoch_phases.active.end + { + match active_epoch_foresters[0].get_current_light_slot(slot) { + Ok(ls) => ls, + Err(e) => { + println!("WARN: Could not calculate current light slot from PDA (using approximation): {:?}", e); + (slot - epoch_phases.active.start) + / protocol_config.config.slot_length // Fallback calculation + } + } + } else { + println!( + "WARN: Currently not in the active phase for epoch {}. Showing assignments from light slot index 0.", + current_active_epoch + ); + 0 + }; + + println!( + "Forester assignments for tree {} (queue {}) starting light slot index {}:", + tree, queue, current_light_slot_index + ); + + for i in 0..=10 { + let light_slot_to_check = current_light_slot_index + i; + if light_slot_to_check < num_light_slots { + let eligible_forester_slot_index = + match ForesterEpochPda::get_eligible_forester_index( + light_slot_to_check, + &queue, + total_epoch_weight, + current_active_epoch, + ) { + Ok(idx) => idx, + Err(e) => { + println!( + " Light Slot Index {}: ERROR calculating index: {:?}", + light_slot_to_check, e + ); + continue; + } + }; + + let assigned_forester = active_epoch_foresters + .iter() + .find(|pda| pda.is_eligible(eligible_forester_slot_index)); + + if let Some(forester_pda) = assigned_forester { + println!( + " Light Slot Index {}: Authority: {} (Eligible Index: {})", + light_slot_to_check, + forester_pda.authority, + eligible_forester_slot_index + ); + } else { + println!( + " Light Slot Index {}: UNASSIGNED (Eligible Index: {}) - Error in logic?", + light_slot_to_check, eligible_forester_slot_index + ); + } + } else { + println!( + " Light Slot Index {}: (Exceeds epoch length)", + light_slot_to_check + ); + break; + } + } + } else { + println!( + "Check FAILED: Tree {} is missing forester assignment starting at least at light slot index {} in epoch {}.", + tree, first_missing_slot, current_active_epoch + ); + } + } + } + } else { + if current_epoch_pda_entry.is_none() { + println!( + "ERROR: Could not find EpochPda for active epoch {}. Cannot check forester assignments.", + current_active_epoch + ); + } + } +} diff --git a/forester/src/send_transaction.rs b/forester/src/send_transaction.rs index 6b19259627..55235d5e2a 100644 --- a/forester/src/send_transaction.rs +++ b/forester/src/send_transaction.rs @@ -3,7 +3,6 @@ use std::{ atomic::{AtomicBool, AtomicUsize, Ordering}, Arc, }, - time::Duration, vec, }; @@ -12,10 +11,12 @@ use account_compression::utils::constants::{ STATE_MERKLE_TREE_CHANGELOG, STATE_NULLIFIER_QUEUE_VALUES, }; use async_trait::async_trait; +use futures::stream::iter; +use futures::StreamExt; use forester_utils::forester_epoch::TreeAccounts; use light_client::{ indexer::Indexer, - rpc::{RetryConfig, RpcConnection, RpcError}, + rpc::{RetryConfig, RpcConnection}, rpc_pool::SolanaRpcPool, }; use light_compressed_account::TreeType; @@ -33,11 +34,11 @@ use solana_sdk::{ hash::Hash, instruction::Instruction, pubkey::Pubkey, - signature::{Keypair, Signature, Signer}, + signature::{Keypair, Signer}, transaction::Transaction, }; use tokio::{join, sync::Mutex, time::Instant}; -use tracing::{info, warn}; +use tracing::{info, warn, debug, error}; use url::Url; use crate::{ @@ -68,6 +69,31 @@ pub trait TransactionBuilder { ) -> Result<(Vec, u64)>; } +#[derive(Debug, Clone, Copy)] +pub struct CapConfig { + pub rec_fee_microlamports_per_cu: u64, + pub min_fee_lamports: u64, + pub max_fee_lamports: u64, + pub compute_unit_limit: u64, +} + +#[derive(Debug, Clone, Copy)] +pub struct SendBatchedTransactionsConfig { + pub num_batches: u64, + pub build_transaction_batch_config: BuildTransactionBatchConfig, + pub queue_config: QueueConfig, + pub retry_config: RetryConfig, + pub light_slot_length: u64, +} + +#[derive(Debug, Clone, Copy)] +pub struct BuildTransactionBatchConfig { + pub batch_size: u64, + pub compute_unit_price: Option, + pub compute_unit_limit: Option, + pub enable_priority_fees: bool, +} + /// Calculate the compute unit price in microLamports based on the target lamports and compute units pub fn calculate_compute_unit_price(target_lamports: u64, compute_units: u64) -> u64 { ((target_lamports * 1_000_000) as f64 / compute_units as f64).ceil() as u64 @@ -107,23 +133,24 @@ pub async fn send_batched_transactions( transaction_builder: &T, ) -> Result { let start_time = Instant::now(); + let tree_id_str = tree_accounts.merkle_tree.to_string(); + let queue_id_str = tree_accounts.queue.to_string(); let num_sent_transactions = Arc::new(AtomicUsize::new(0)); let cancel_signal = Arc::new(AtomicBool::new(false)); - let (tx_sender, mut tx_receiver) = - tokio::sync::mpsc::channel::>(120); - let processor_pool = pool.clone(); let queue_length = if tree_accounts.tree_type == TreeType::StateV1 { STATE_NULLIFIER_QUEUE_VALUES } else { ADDRESS_QUEUE_VALUES }; + let start_index = if tree_accounts.tree_type == TreeType::StateV1 { config.queue_config.state_queue_start_index } else { config.queue_config.address_queue_start_index }; + let length = if tree_accounts.tree_type == TreeType::StateV1 { config.queue_config.state_queue_length } else { @@ -131,7 +158,22 @@ pub async fn send_batched_transactions( }; let queue_item_data = { - let mut rpc = pool.get_connection().await?; + let context_str = format!( + "send_batched_transactions (fetch_queue_item_data), tree: {}", + tree_accounts.merkle_tree + ); + debug!("{} Attempting to get RPC connection...", context_str); + let rpc_result = pool.get_connection().await; + match rpc_result { + Ok(_) => { + debug!("{} Successfully got RPC connection.", context_str); + } + Err(ref e) => { + error!("{} Failed to get RPC connection: {:?}", context_str, e); + } + } + let mut rpc = rpc_result?; + fetch_queue_item_data( &mut *rpc, &tree_accounts.queue, @@ -143,21 +185,54 @@ pub async fn send_batched_transactions( }; if queue_item_data.is_empty() { + debug!("{} Queue is empty, no transactions to send.", tree_id_str); return Ok(0); } let (recent_blockhash, current_block_height) = { - let mut rpc = pool.get_connection().await?; + let context_str = format!( + "send_batched_transactions (blockhash/height), tree: {}", + tree_id_str + ); + debug!("{} Attempting to get RPC connection...", context_str); + let rpc_result = pool.get_connection().await; + match rpc_result { + Ok(_) => { + debug!("{} Successfully got RPC connection.", context_str); + } + Err(ref e) => { + error!("{} Failed to get RPC connection: {:?}", context_str, e); + } + } + let mut rpc = rpc_result?; + ( rpc.get_latest_blockhash().await?, rpc.get_block_height().await?, ) }; let last_valid_block_height = current_block_height + 150; - let forester_epoch_pda_pubkey = - get_forester_epoch_pda_from_authority(derivation, transaction_builder.epoch()).0; + let priority_fee = if config.build_transaction_batch_config.enable_priority_fees { - let rpc = pool.get_connection().await?; + let context_str = format!( + "send_batched_transactions (priority_fee), tree: {}", + tree_accounts.merkle_tree + ); + debug!("{} Attempting to get RPC connection...", context_str); + let rpc_result = pool.get_connection().await; + match rpc_result { + Ok(_) => { + debug!("{} Successfully got RPC connection.", context_str); + } + Err(ref e) => { + error!("{} Failed to get RPC connection: {:?}", context_str, e); + } + } + let rpc = rpc_result?; + + let forester_epoch_pda_pubkey = + get_forester_epoch_pda_from_authority(derivation, transaction_builder.epoch()).0; + let account_keys = vec![ payer.pubkey(), forester_epoch_pda_pubkey, @@ -170,39 +245,6 @@ pub async fn send_batched_transactions( 10_000 // Minimum priority fee when disabled }; - let num_sent_clone = Arc::clone(&num_sent_transactions); - let cancel_clone = Arc::clone(&cancel_signal); - - let processor_handle = tokio::spawn(async move { - while let Some(result) = tx_receiver.recv().await { - match result { - Ok(signature) => { - num_sent_clone.fetch_add(1, Ordering::SeqCst); - info!( - "tree {} / queue {} / tx {:?}", - tree_accounts.merkle_tree.to_string(), - tree_accounts.queue.to_string(), - signature - ); - } - Err(e) => { - warn!("Transaction failed: {:?}", e); - - let mut rpc = processor_pool.get_connection().await; - if let Err(e) = &rpc { - warn!("Failed to get RPC connection: {}", e); - } - if let Ok(rpc) = rpc.as_mut() { - if !rpc.should_retry(&e) { - cancel_clone.store(true, Ordering::SeqCst); - break; - } - } - } - } - } - }); - let work_items: Vec = queue_item_data .into_iter() .map(|data| WorkItem { @@ -211,20 +253,23 @@ pub async fn send_batched_transactions( }) .collect(); - let buffer_duration = Duration::from_secs(2); - let adjusted_timeout = if config.retry_config.timeout > buffer_duration { - config.retry_config.timeout - buffer_duration - } else { - return Ok(0); - }; - let timeout_deadline = start_time + adjusted_timeout; + let timeout_deadline = start_time + config.retry_config.timeout; + + const MAX_CONCURRENT_SENDS: usize = 1; + info!(tree = %tree_id_str, "Starting transaction sending loop. Timeout deadline: {:?}. Max concurrent sends: {}", timeout_deadline, MAX_CONCURRENT_SENDS); for work_chunk in work_items.chunks(config.build_transaction_batch_config.batch_size as usize) { - if cancel_signal.load(Ordering::SeqCst) || Instant::now() >= timeout_deadline { + if cancel_signal.load(Ordering::SeqCst) { + info!(tree = %tree_id_str, "Cancellation signal received, stopping batch processing."); break; } - - let (transactions, _) = transaction_builder + if Instant::now() >= timeout_deadline { + warn!(tree = %tree_id_str, "Reached timeout deadline before processing next chunk, stopping."); + break; + } + debug!(tree = %tree_id_str, "Processing chunk of size {}", work_chunk.len()); + let build_start = Instant::now(); + let (transactions, _obtained_last_valid_block_height) = match transaction_builder .build_signed_transaction_batch( payer, derivation, @@ -234,78 +279,109 @@ pub async fn send_batched_transactions( work_chunk, config.build_transaction_batch_config, ) - .await?; - - let now = Instant::now(); - if now >= timeout_deadline { - break; - } - - for tx in transactions { - if cancel_signal.load(Ordering::SeqCst) { + .await { + Ok(res) => res, + Err(e) => { + error!(tree = %tree_id_str, "Failed to build transaction batch: {:?}", e); + cancel_signal.store(true, Ordering::SeqCst); break; } + }; + debug!(tree = %tree_id_str, "Built {} transactions in {:?}", transactions.len(), build_start.elapsed()); - let now = Instant::now(); - if now >= timeout_deadline { - warn!("Reached timeout deadline, stopping batch processing"); - break; - } + if Instant::now() >= timeout_deadline { + warn!(tree = %tree_id_str, "Reached timeout deadline after building transactions, stopping chunk processing."); + break; + } + if transactions.is_empty() { + debug!(tree = %tree_id_str, "Built batch resulted in 0 transactions, skipping send."); + continue; + } + let transaction_stream = iter(transactions); - let tx_sender = tx_sender.clone(); + let send_futures_stream = transaction_stream.map(|tx| { let pool_clone = pool.clone(); - let config = RpcSendTransactionConfig { + let rpc_send_config = RpcSendTransactionConfig { skip_preflight: true, max_retries: Some(0), preflight_commitment: Some(CommitmentLevel::Confirmed), ..Default::default() }; - let cancel_signal_clone = cancel_signal.clone(); + let num_sent_transactions_clone = num_sent_transactions.clone(); let deadline = timeout_deadline; + let tree_id_str_clone = tree_id_str.clone(); + let queue_id_str_clone = queue_id_str.clone(); - tokio::spawn(async move { + async move { if cancel_signal_clone.load(Ordering::SeqCst) || Instant::now() >= deadline { return; } - if let Ok(mut rpc) = pool_clone.get_connection().await { - let result = rpc.process_transaction_with_config(tx, config).await; - if !cancel_signal_clone.load(Ordering::SeqCst) { - let _ = tx_sender.send(result).await; + let tx_signature = tx.signatures.first().copied().unwrap_or_default(); + let tx_signature_str = tx_signature.to_string(); + let context_str = format!("send_batched_transactions (concurrent sender), tree: {}, tx_sig_prefix: {}", tree_id_str_clone, &tx_signature_str[..8]); + + debug!(context = %context_str, "Attempting to get RPC connection..."); + let rpc_result = pool_clone.get_connection().await; + + match rpc_result { + Ok(mut rpc) => { + debug!(context = %context_str, "Successfully got RPC connection."); + if Instant::now() >= deadline { + warn!(context = %context_str, "Reached timeout deadline after getting connection, skipping send"); + return; + } + + let result = rpc.process_transaction_with_config(tx, rpc_send_config).await; + + if !cancel_signal_clone.load(Ordering::SeqCst) { + match result { + Ok(signature) => { + num_sent_transactions_clone.fetch_add(1, Ordering::SeqCst); + info!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %signature, "Transaction sent successfully"); + } + Err(e) => { + warn!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %tx_signature_str, "Transaction send/process failed: {:?}", e); + let retry_check_context = format!("send_batched_transactions (retry check), tree: {}", tree_id_str_clone); + debug!(context = %retry_check_context, "Attempting RPC connection for retry check..."); + match pool_clone.get_connection().await { + Ok(check_rpc) => { + debug!(context = %retry_check_context, "Got RPC connection for retry check."); + if !check_rpc.should_retry(&e) { + warn!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %tx_signature_str, "Non-retryable RPC error detected, setting cancel signal: {:?}", e); + cancel_signal_clone.store(true, Ordering::SeqCst); + } else { + debug!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %tx_signature_str, "Retryable RPC error encountered: {:?}", e); + } + } + Err(pool_err) => { + warn!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %tx_signature_str, "Failed to get RPC connection for retry check: {}", pool_err); + cancel_signal_clone.store(true, Ordering::SeqCst); + } + } + } + } + } else { + debug!(context = %context_str, "Cancelled during transaction processing, discarding result."); + } + } + Err(ref e) => { + error!(context = %context_str, "Failed to get RPC connection: {:?}", e); + return; } } - }); - } - } - drop(tx_sender); - processor_handle.await?; - Ok(num_sent_transactions.load(Ordering::SeqCst)) -} - -#[derive(Debug, Clone, Copy)] -pub struct CapConfig { - pub rec_fee_microlamports_per_cu: u64, - pub min_fee_lamports: u64, - pub max_fee_lamports: u64, - pub compute_unit_limit: u64, -} + } + }); -#[derive(Debug, Clone, Copy)] -pub struct SendBatchedTransactionsConfig { - pub num_batches: u64, - pub build_transaction_batch_config: BuildTransactionBatchConfig, - pub queue_config: QueueConfig, - pub retry_config: RetryConfig, - pub light_slot_length: u64, -} + info!(tree = %tree_id_str, "Executing batch of {} sends with concurrency limit {}", work_chunk.len(), MAX_CONCURRENT_SENDS); + let exec_start = Instant::now(); + send_futures_stream.for_each_concurrent(MAX_CONCURRENT_SENDS, |f| f).await; + info!(tree = %tree_id_str, "Finished executing batch in {:?}", exec_start.elapsed()); + } -#[derive(Debug, Clone, Copy)] -pub struct BuildTransactionBatchConfig { - pub batch_size: u64, - pub compute_unit_price: Option, - pub compute_unit_limit: Option, - pub enable_priority_fees: bool, + info!(tree = %tree_id_str, "Transaction sending loop finished. Total transactions sent attempt count: {}", num_sent_transactions.load(Ordering::Relaxed)); + Ok(num_sent_transactions.load(Ordering::SeqCst)) } pub struct EpochManagerTransactions> { @@ -402,8 +478,9 @@ pub async fn fetch_proofs_and_create_instructions Date: Sat, 3 May 2025 19:15:21 +0100 Subject: [PATCH 05/24] refactor status and slot handling --- forester-utils/src/forester_epoch.rs | 16 +- forester/src/epoch_manager.rs | 213 ++++++++++++++++++++------- forester/src/forester_status.rs | 168 ++++++++++++++++++++- 3 files changed, 333 insertions(+), 64 deletions(-) diff --git a/forester-utils/src/forester_epoch.rs b/forester-utils/src/forester_epoch.rs index 2320e45ef1..c1ed11e774 100644 --- a/forester-utils/src/forester_epoch.rs +++ b/forester-utils/src/forester_epoch.rs @@ -84,11 +84,19 @@ pub fn get_schedule_for_queue( protocol_config: &ProtocolConfig, total_epoch_weight: u64, epoch: u64, + current_phase_start_slot: u64, ) -> Vec> { let mut vec = Vec::new(); - let start_slot = 0; - // TODO: enforce that active_phase_length is a multiple of slot_length - let end_slot = start_slot + (protocol_config.active_phase_length / protocol_config.slot_length); + + let current_light_slot = if start_solana_slot > current_phase_start_slot { + (start_solana_slot - current_phase_start_slot) / protocol_config.slot_length + } else { + 0 + }; + + let start_slot = current_light_slot; + start_solana_slot = current_phase_start_slot + (current_light_slot * protocol_config.slot_length); + let end_slot = (protocol_config.active_phase_length / protocol_config.slot_length); for light_slot in start_slot..end_slot { let forester_index = ForesterEpochPda::get_eligible_forester_index( @@ -121,6 +129,7 @@ pub fn get_schedule_for_forester_in_queue( &forester_epoch_pda.protocol_config, total_epoch_weight, forester_epoch_pda.epoch, + forester_epoch_pda.epoch_active_phase_start_slot, ); slots.iter_mut().for_each(|slot_option| { if let Some(slot) = slot_option { @@ -503,6 +512,7 @@ mod test { &protocol_config, total_epoch_weight, epoch, + 0 ); assert_eq!( diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 85403c9a4b..1fff7a401d 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -23,8 +23,8 @@ use light_registry::{ utils::{get_epoch_pda_address, get_forester_epoch_pda_from_authority}, EpochPda, ForesterEpochPda, }; -use solana_program::{instruction::InstructionError, pubkey::Pubkey}; use solana_program::native_token::LAMPORTS_PER_SOL; +use solana_program::{instruction::InstructionError, pubkey::Pubkey}; use solana_sdk::{signature::Signer, transaction::TransactionError}; use tokio::{ sync::{broadcast, broadcast::error::RecvError, mpsc, oneshot, Mutex}, @@ -36,7 +36,7 @@ use tracing::{debug, error, info, info_span, instrument, trace, warn}; use crate::{ batch_processor::{process_batched_operations, BatchContext}, errors::{ - ChannelError, ConfigurationError, ForesterError, InitializationError, RegistrationError, + ChannelError, ForesterError, InitializationError, RegistrationError, WorkReportError, }, indexer_type::{rollover_address_merkle_tree, rollover_state_merkle_tree, IndexerType}, @@ -195,18 +195,16 @@ impl + IndexerType> EpochManager { loop { interval.tick().await; match self.rpc_pool.get_connection().await { - Ok(mut rpc) => { - match rpc.get_balance(&self.config.payer_keypair.pubkey()).await { - Ok(balance) => { - let balance_in_sol = balance as f64 / (LAMPORTS_PER_SOL as f64); - update_forester_sol_balance( - &self.config.payer_keypair.pubkey().to_string(), - balance_in_sol, - ); - debug!("Current SOL balance: {} SOL", balance_in_sol); - }, - Err(e) => error!("Failed to get balance: {:?}", e), + Ok(mut rpc) => match rpc.get_balance(&self.config.payer_keypair.pubkey()).await { + Ok(balance) => { + let balance_in_sol = balance as f64 / (LAMPORTS_PER_SOL as f64); + update_forester_sol_balance( + &self.config.payer_keypair.pubkey().to_string(), + balance_in_sol, + ); + debug!("Current SOL balance: {} SOL", balance_in_sol); } + Err(e) => error!("Failed to get balance: {:?}", e), }, Err(e) => error!("Failed to get RPC connection for balance check: {:?}", e), } @@ -377,7 +375,7 @@ impl + IndexerType> EpochManager { let current_phases = get_epoch_phases(&self.protocol_config, current_epoch); let previous_epoch = current_epoch.saturating_sub(1); - // Process previous epoch if still in active or later phase + // Process the previous epoch if still in active or later phase if slot > current_phases.registration.start { debug!("Processing previous epoch: {}", previous_epoch); tx.send(previous_epoch).await?; @@ -828,7 +826,6 @@ impl + IndexerType> EpochManager { epoch_info.phases.active.end ); 'outer: while estimated_slot < epoch_info.phases.active.end { - let index_and_forester_slot = tree .slots .iter() @@ -839,35 +836,51 @@ impl + IndexerType> EpochManager { let forester_slot = forester_slot.as_ref().unwrap().clone(); info!( "Found eligible slot: {:?}. Target start: {}, Target end: {}", - forester_slot.slot, forester_slot.start_solana_slot, forester_slot.end_solana_slot + forester_slot.slot, + forester_slot.start_solana_slot, + forester_slot.end_solana_slot ); - let context_str = format!("process_queue (wait_until_slot_reached), tree: {}", tree.tree_accounts.merkle_tree); + let context_str = format!( + "process_queue (wait_until_slot_reached), tree: {}", + tree.tree_accounts.merkle_tree + ); debug!(context = %context_str, "Attempting to get RPC connection for wait..."); let rpc_result = self.rpc_pool.get_connection().await; match rpc_result { - Ok(_) => { debug!(context = %context_str, "Successfully got RPC connection for wait."); } - Err(ref e) => { error!(context = %context_str, "Failed to get RPC connection for wait: {:?}", e); } + Ok(_) => { + debug!(context = %context_str, "Successfully got RPC connection for wait."); + } + Err(ref e) => { + error!(context = %context_str, "Failed to get RPC connection for wait: {:?}", e); + } } let mut rpc = rpc_result?; info!( - "Current estimated solana slot: {}, waiting for slot {} to begin", + "Current estimated solana slot: {}, waiting for slot {} to begin", self.slot_tracker.estimated_current_slot(), forester_slot.start_solana_slot - ); + ); if let Err(e) = wait_until_slot_reached( &mut *rpc, &self.slot_tracker, forester_slot.start_solana_slot, ) - .await { - error!("Error waiting for slot {} to start: {:?}. Skipping slot.", forester_slot.start_solana_slot, e); + .await + { + error!( + "Error waiting for slot {} to start: {:?}. Skipping slot.", + forester_slot.start_solana_slot, e + ); tree.slots[slot_index] = None; continue 'outer; } - info!("Reached start slot {}. Beginning processing window until slot {}.", forester_slot.start_solana_slot, forester_slot.end_solana_slot); + info!( + "Reached start slot {}. Beginning processing window until slot {}.", + forester_slot.start_solana_slot, forester_slot.end_solana_slot + ); 'inner: loop { estimated_slot = self.slot_tracker.estimated_current_slot(); if estimated_slot >= forester_slot.end_solana_slot { @@ -881,7 +894,40 @@ impl + IndexerType> EpochManager { debug!( "Inner loop iteration for slot {:?}. Current estimated: {}, End: {}", forester_slot.slot, estimated_slot, forester_slot.end_solana_slot - ); + ); + + let current_light_slot = (estimated_slot - epoch_info.phases.active.start) + / epoch_pda.protocol_config.slot_length; + if current_light_slot != forester_slot.slot { + warn!( + "Current light slot {} differs from processing slot {}. Exiting slot processing.", + current_light_slot, forester_slot.slot + ); + break 'inner; + } + let eligible_forester_slot_index = + match ForesterEpochPda::get_eligible_forester_index( + current_light_slot, + &tree.tree_accounts.queue, + epoch_pda.total_epoch_weight.unwrap(), + epoch_info.epoch, + ) { + Ok(idx) => idx, + Err(e) => { + error!("Failed to calculate eligible forester index: {:?}", e); + break 'inner; + } + }; + + if !epoch_pda.is_eligible(eligible_forester_slot_index) { + warn!( + "Forester {} is no longer eligible to process tree {} in light slot {}. Exiting slot processing.", + self.config.payer_keypair.pubkey(), + tree.tree_accounts.merkle_tree, + current_light_slot + ); + break 'inner; + } let mut items_processed_this_iteration = 0; let mut iteration_failed = false; @@ -898,7 +944,10 @@ impl + IndexerType> EpochManager { transaction_timeout_buffer, ); - trace!("Calculated remaining time timeout for send_batched_transactions: {:?}", remaining_time_timeout); + trace!( + "Calculated remaining time timeout for send_batched_transactions: {:?}", + remaining_time_timeout + ); let batched_tx_config = SendBatchedTransactionsConfig { num_batches: 1, @@ -925,7 +974,10 @@ impl + IndexerType> EpochManager { phantom: std::marker::PhantomData::, }; - info!("Attempting to send transactions within slot {:?}", forester_slot.slot); + info!( + "Attempting to send transactions within slot {:?}", + forester_slot.slot + ); match send_batched_transactions( &self.config.payer_keypair, &self.config.derivation_pubkey, @@ -934,34 +986,51 @@ impl + IndexerType> EpochManager { tree.tree_accounts, &transaction_builder, ) - .await + .await { Ok(num_sent) => { if num_sent > 0 { trace!("{} transactions sent in this iteration", num_sent); let iteration_duration = processing_start_time.elapsed(); - queue_metric_update(epoch_info.epoch, num_sent, iteration_duration).await; - self.increment_processed_items_count(epoch_info.epoch, num_sent).await; + queue_metric_update( + epoch_info.epoch, + num_sent, + iteration_duration, + ) + .await; + self.increment_processed_items_count( + epoch_info.epoch, + num_sent, + ) + .await; items_processed_this_iteration = num_sent; - trace!("Checking for rollover readiness after processing batch..."); - if let Err(e) = self.rollover_if_needed(&tree.tree_accounts).await { - error!("Rollover check failed during slot processing: {:?}", e); + trace!( + "Checking for rollover readiness after processing batch..." + ); + if let Err(e) = + self.rollover_if_needed(&tree.tree_accounts).await + { + error!( + "Rollover check failed during slot processing: {:?}", + e + ); } else { trace!("Rollover check completed."); } - } else { info!("send_batched_transactions processed 0 items. Queue likely empty for this attempt."); } } Err(e) => { - error!("Failed to send transactions within slot {:?}: {:?}", forester_slot.slot, e); + error!( + "Failed to send transactions within slot {:?}: {:?}", + forester_slot.slot, e + ); iteration_failed = true; } } - } - else if tree.tree_accounts.tree_type == TreeType::StateV2 + } else if tree.tree_accounts.tree_type == TreeType::StateV2 || tree.tree_accounts.tree_type == TreeType::AddressV2 { let batch_context = BatchContext { @@ -974,21 +1043,40 @@ impl + IndexerType> EpochManager { output_queue: tree.tree_accounts.queue, ixs_per_tx: self.config.transaction_config.batch_ixs_per_tx, }; - match process_batched_operations(batch_context, tree.tree_accounts.tree_type).await { + match process_batched_operations( + batch_context, + tree.tree_accounts.tree_type, + ) + .await + { Ok(processed_count) => { if processed_count > 0 { info!( - "Processed {} V2 operations for tree type {:?}", - processed_count, tree.tree_accounts.tree_type - ); + "Processed {} V2 operations for tree type {:?}", + processed_count, tree.tree_accounts.tree_type + ); let iteration_duration = processing_start_time.elapsed(); - queue_metric_update(epoch_info.epoch, processed_count, iteration_duration).await; - self.increment_processed_items_count(epoch_info.epoch, processed_count).await; + queue_metric_update( + epoch_info.epoch, + processed_count, + iteration_duration, + ) + .await; + self.increment_processed_items_count( + epoch_info.epoch, + processed_count, + ) + .await; items_processed_this_iteration = processed_count; trace!("Checking for V2 rollover readiness after processing batch..."); - if let Err(e) = self.rollover_if_needed(&tree.tree_accounts).await { - error!("V2 Rollover check failed during slot processing: {:?}", e); + if let Err(e) = + self.rollover_if_needed(&tree.tree_accounts).await + { + error!( + "V2 Rollover check failed during slot processing: {:?}", + e + ); } else { trace!("V2 Rollover check completed."); } @@ -1005,12 +1093,18 @@ impl + IndexerType> EpochManager { } } } else { - warn!("Unsupported tree type encountered in process_queue: {:?}", tree.tree_accounts.tree_type); + warn!( + "Unsupported tree type encountered in process_queue: {:?}", + tree.tree_accounts.tree_type + ); iteration_failed = true; } if iteration_failed { - error!("Exiting inner loop for slot {:?} due to processing error.", forester_slot.slot); + error!( + "Exiting inner loop for slot {:?} due to processing error.", + forester_slot.slot + ); break 'inner; } @@ -1026,7 +1120,10 @@ impl + IndexerType> EpochManager { } if self.slot_tracker.estimated_current_slot() >= forester_slot.end_solana_slot { - info!("Exiting inner loop for slot {:?} after sleep/yield time check.", forester_slot.slot); + info!( + "Exiting inner loop for slot {:?} after sleep/yield time check.", + forester_slot.slot + ); break 'inner; } } @@ -1042,10 +1139,12 @@ impl + IndexerType> EpochManager { } tokio::task::yield_now().await; estimated_slot = self.slot_tracker.estimated_current_slot(); - } - info!("Exiting process_queue for epoch {}, tree {}", epoch_info.epoch, tree.tree_accounts.merkle_tree); + info!( + "Exiting process_queue for epoch {}, tree {}", + epoch_info.epoch, tree.tree_accounts.merkle_tree + ); Ok(()) } @@ -1212,13 +1311,21 @@ impl + IndexerType> EpochManager { } } -fn calculate_remaining_time_or_default(current_slot: u64, end_slot: u64, buffer_duration: Duration) -> Duration { +fn calculate_remaining_time_or_default( + current_slot: u64, + end_slot: u64, + buffer_duration: Duration, +) -> Duration { if current_slot >= end_slot { return Duration::ZERO; } let slots_remaining = end_slot - current_slot; - let base_remaining_duration = slot_duration().checked_mul(slots_remaining as u32).unwrap_or_default(); - base_remaining_duration.checked_sub(buffer_duration).unwrap_or_else(|| Duration::ZERO) + let base_remaining_duration = slot_duration() + .checked_mul(slots_remaining as u32) + .unwrap_or_default(); + base_remaining_duration + .checked_sub(buffer_duration) + .unwrap_or_else(|| Duration::ZERO) } #[instrument( diff --git a/forester/src/forester_status.rs b/forester/src/forester_status.rs index 7919e2bd13..82773ee59b 100644 --- a/forester/src/forester_status.rs +++ b/forester/src/forester_status.rs @@ -9,7 +9,7 @@ use crate::{ ForesterConfig, }; use anchor_lang::{AccountDeserialize, Discriminator}; -use forester_utils::forester_epoch::get_epoch_phases; +use forester_utils::forester_epoch::{get_epoch_phases, TreeAccounts}; use itertools::Itertools; use light_client::rpc::{RpcConnection, SolanaRpcConnection}; use light_compressed_account::TreeType; @@ -222,11 +222,154 @@ pub async fn fetch_forester_status(args: &StatusArgs) { } } + println!("\n=== CURRENT ACTIVE FORESTER ASSIGNMENTS ==="); + let active_epoch_foresters: Vec = forester_epoch_pdas + .iter() + .filter(|item| item.epoch == current_active_epoch) + .cloned() + .collect(); + + let current_epoch_pda_entry = epoch_pdas + .iter() + .find(|pda| pda.epoch == current_active_epoch); + + let protocol_config = protocol_config_pdas[0].clone(); + + if !active_epoch_foresters.is_empty() && current_epoch_pda_entry.is_some() { + print_current_forester_assignments( + slot, + current_active_epoch, + active_epoch_foresters, + &trees, + current_epoch_pda_entry, + &protocol_config, + ); + } else { + println!("No active foresters found for the current epoch."); + } + push_metrics(&config.external_services.pushgateway_url) .await .unwrap(); } +fn print_current_forester_assignments( + slot: Slot, + current_active_epoch: u64, + active_epoch_foresters: Vec, + trees: &Vec, + current_epoch_pda_entry: Option<&EpochPda>, + protocol_config: &ProtocolConfigPda, +) { + if let Some(_current_epoch_pda) = current_epoch_pda_entry { + if active_epoch_foresters.is_empty() { + println!( + "ERROR: No foresters registered for active epoch {}", + current_active_epoch + ); + return; + } + + let total_epoch_weight = match active_epoch_foresters[0].total_epoch_weight { + Some(w) if w > 0 => w, + _ => { + println!( + "ERROR: Registration not finalized (total_epoch_weight is None or 0) for epoch {}.", + current_active_epoch + ); + return; + } + }; + + let epoch_phases = get_epoch_phases(&protocol_config.config, current_active_epoch); + + if slot < epoch_phases.active.start || slot >= epoch_phases.active.end { + println!( + "Info: Not currently within the active phase of epoch {}.", + current_active_epoch + ); + return; + } + + if protocol_config.config.slot_length == 0 { + println!( + "ERROR: ProtocolConfig slot_length is zero. Cannot calculate light slots." + ); + return; + } + + let current_light_slot_index = + (slot - epoch_phases.active.start) / protocol_config.config.slot_length; + let start_solana_slot_of_current_light_slot = epoch_phases.active.start + + current_light_slot_index * protocol_config.config.slot_length; + let end_solana_slot_of_current_light_slot = + start_solana_slot_of_current_light_slot + protocol_config.config.slot_length; + + let slots_remaining_in_light_slot = + end_solana_slot_of_current_light_slot.saturating_sub(slot); + let time_remaining_secs = slots_remaining_in_light_slot as f64 * 0.460; + + println!( + "Current Light Slot Index: {} (Solana slots {}-{}, Approx. {:.2}s remaining)", + current_light_slot_index, + start_solana_slot_of_current_light_slot, + end_solana_slot_of_current_light_slot - 1, + time_remaining_secs + ); + + println!("Queue processors for the current light slot:"); + println!("━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━"); + println!("│ Tree Type │ Tree Address │ Forester │"); + println!("┼───────────┼──────────────────────────────────────────┼──────────────────────────────────────────┤"); + + for tree in trees { + let eligible_forester_slot_index = match ForesterEpochPda::get_eligible_forester_index( + current_light_slot_index, + &tree.queue, + total_epoch_weight, + current_active_epoch, + ) { + Ok(idx) => idx, + Err(e) => { + println!( + "│ {} │ {} │ ERROR: {:?} │", + format!("{:9}", tree.tree_type), + tree.merkle_tree, + e + ); + continue; + } + }; + + let assigned_forester = active_epoch_foresters + .iter() + .find(|pda| pda.is_eligible(eligible_forester_slot_index)); + + if let Some(forester_pda) = assigned_forester { + println!( + "│ {} │ {} │ {} │", + format!("{:9}", tree.tree_type), + tree.merkle_tree, + forester_pda.authority + ); + } else { + println!( + "│ {} │ {} │ UNASSIGNED (Eligible Index: {}) │", + format!("{:9}", tree.tree_type), + tree.merkle_tree, + eligible_forester_slot_index + ); + } + } + println!("━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━"); + } else { + println!( + "ERROR: Could not find EpochPda for active epoch {}. Cannot determine forester assignments.", + current_active_epoch + ); + } +} + fn print_tree_schedule_by_forester( slot: Slot, current_active_epoch: u64, @@ -397,12 +540,21 @@ fn print_tree_schedule_by_forester( .find(|pda| pda.is_eligible(eligible_forester_slot_index)); if let Some(forester_pda) = assigned_forester { - println!( - " Light Slot Index {}: Authority: {} (Eligible Index: {})", - light_slot_to_check, - forester_pda.authority, - eligible_forester_slot_index - ); + if light_slot_to_check == current_light_slot_index { + println!( + " Light Slot Index {} (CURRENT): Authority: {} (Eligible Index: {})", + light_slot_to_check, + forester_pda.authority, + eligible_forester_slot_index + ); + } else { + println!( + " Light Slot Index {}: Authority: {} (Eligible Index: {})", + light_slot_to_check, + forester_pda.authority, + eligible_forester_slot_index + ); + } } else { println!( " Light Slot Index {}: UNASSIGNED (Eligible Index: {}) - Error in logic?", @@ -433,4 +585,4 @@ fn print_tree_schedule_by_forester( ); } } -} +} \ No newline at end of file From f534b1e456c0375fcb7582ddfe87f9de22c3a3e6 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Sat, 3 May 2025 22:11:14 +0100 Subject: [PATCH 06/24] format --- forester-utils/src/forester_epoch.rs | 7 ++- forester/src/epoch_manager.rs | 10 ++-- forester/src/errors.rs | 4 ++ forester/src/forester_status.rs | 56 ++++++++----------- forester/src/rollover/operations.rs | 10 +--- forester/src/send_transaction.rs | 15 ++--- sdk-libs/client/src/indexer/photon_indexer.rs | 38 +++++++------ 7 files changed, 66 insertions(+), 74 deletions(-) diff --git a/forester-utils/src/forester_epoch.rs b/forester-utils/src/forester_epoch.rs index c1ed11e774..42201a96b4 100644 --- a/forester-utils/src/forester_epoch.rs +++ b/forester-utils/src/forester_epoch.rs @@ -95,8 +95,9 @@ pub fn get_schedule_for_queue( }; let start_slot = current_light_slot; - start_solana_slot = current_phase_start_slot + (current_light_slot * protocol_config.slot_length); - let end_slot = (protocol_config.active_phase_length / protocol_config.slot_length); + start_solana_slot = + current_phase_start_slot + (current_light_slot * protocol_config.slot_length); + let end_slot = protocol_config.active_phase_length / protocol_config.slot_length; for light_slot in start_slot..end_slot { let forester_index = ForesterEpochPda::get_eligible_forester_index( @@ -512,7 +513,7 @@ mod test { &protocol_config, total_epoch_weight, epoch, - 0 + 0, ); assert_eq!( diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 1fff7a401d..6dda9faf4a 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -23,8 +23,9 @@ use light_registry::{ utils::{get_epoch_pda_address, get_forester_epoch_pda_from_authority}, EpochPda, ForesterEpochPda, }; -use solana_program::native_token::LAMPORTS_PER_SOL; -use solana_program::{instruction::InstructionError, pubkey::Pubkey}; +use solana_program::{ + instruction::InstructionError, native_token::LAMPORTS_PER_SOL, pubkey::Pubkey, +}; use solana_sdk::{signature::Signer, transaction::TransactionError}; use tokio::{ sync::{broadcast, broadcast::error::RecvError, mpsc, oneshot, Mutex}, @@ -36,8 +37,7 @@ use tracing::{debug, error, info, info_span, instrument, trace, warn}; use crate::{ batch_processor::{process_batched_operations, BatchContext}, errors::{ - ChannelError, ForesterError, InitializationError, RegistrationError, - WorkReportError, + ChannelError, ForesterError, InitializationError, RegistrationError, WorkReportError, }, indexer_type::{rollover_address_merkle_tree, rollover_state_merkle_tree, IndexerType}, metrics::{push_metrics, queue_metric_update, update_forester_sol_balance}, @@ -1325,7 +1325,7 @@ fn calculate_remaining_time_or_default( .unwrap_or_default(); base_remaining_duration .checked_sub(buffer_duration) - .unwrap_or_else(|| Duration::ZERO) + .unwrap_or(Duration::ZERO) } #[instrument( diff --git a/forester/src/errors.rs b/forester/src/errors.rs index 079550527f..dd5087ee92 100644 --- a/forester/src/errors.rs +++ b/forester/src/errors.rs @@ -1,6 +1,7 @@ use std::time::Duration; use light_client::{rpc::errors::RpcError, rpc_pool::PoolError}; +use light_compressed_account::TreeType; use light_registry::errors::RegistryError; use photon_api::apis::{default_api::GetCompressedAccountProofPostError, Error as PhotonApiError}; use solana_program::{program_error::ProgramError, pubkey::Pubkey}; @@ -56,6 +57,9 @@ pub enum ForesterError { #[error("Account deserialization error: {0}")] AccountDeserialization(#[from] AccountDeserializationError), + #[error("Invalid tree type: {0}")] + InvalidTreeType(TreeType), + #[error("Forester error: {error}")] General { error: String }, diff --git a/forester/src/forester_status.rs b/forester/src/forester_status.rs index 82773ee59b..a48c3f0383 100644 --- a/forester/src/forester_status.rs +++ b/forester/src/forester_status.rs @@ -1,24 +1,24 @@ use std::sync::Arc; -use crate::{ - cli::StatusArgs, - metrics::{push_metrics, register_metrics, update_registered_foresters}, - rollover::get_tree_fullness, - run_queue_info, - tree_data_sync::fetch_trees, - ForesterConfig, -}; use anchor_lang::{AccountDeserialize, Discriminator}; use forester_utils::forester_epoch::{get_epoch_phases, TreeAccounts}; use itertools::Itertools; use light_client::rpc::{RpcConnection, SolanaRpcConnection}; use light_compressed_account::TreeType; use light_registry::{protocol_config::state::ProtocolConfigPda, EpochPda, ForesterEpochPda}; -use solana_program::clock::Slot; -use solana_program::pubkey::Pubkey; +use solana_program::{clock::Slot, pubkey::Pubkey}; use solana_sdk::{account::ReadableAccount, commitment_config::CommitmentConfig}; use tracing::{debug, warn}; +use crate::{ + cli::StatusArgs, + metrics::{push_metrics, register_metrics, update_registered_foresters}, + rollover::get_tree_fullness, + run_queue_info, + tree_data_sync::fetch_trees, + ForesterConfig, +}; + pub async fn fetch_forester_status(args: &StatusArgs) { let commitment_config = CommitmentConfig::confirmed(); @@ -292,9 +292,7 @@ fn print_current_forester_assignments( } if protocol_config.config.slot_length == 0 { - println!( - "ERROR: ProtocolConfig slot_length is zero. Cannot calculate light slots." - ); + println!("ERROR: ProtocolConfig slot_length is zero. Cannot calculate light slots."); return; } @@ -332,10 +330,8 @@ fn print_current_forester_assignments( Ok(idx) => idx, Err(e) => { println!( - "│ {} │ {} │ ERROR: {:?} │", - format!("{:9}", tree.tree_type), - tree.merkle_tree, - e + "│ {:9} │ {} │ ERROR: {:?} │", + tree.tree_type, tree.merkle_tree, e ); continue; } @@ -347,17 +343,13 @@ fn print_current_forester_assignments( if let Some(forester_pda) = assigned_forester { println!( - "│ {} │ {} │ {} │", - format!("{:9}", tree.tree_type), - tree.merkle_tree, - forester_pda.authority + "│ {:9} │ {} │ {} │", + tree.tree_type, tree.merkle_tree, forester_pda.authority ); } else { println!( - "│ {} │ {} │ UNASSIGNED (Eligible Index: {}) │", - format!("{:9}", tree.tree_type), - tree.merkle_tree, - eligible_forester_slot_index + "│ {:9} │ {} │ UNASSIGNED (Eligible Index: {}) │", + tree.tree_type, tree.merkle_tree, eligible_forester_slot_index ); } } @@ -577,12 +569,10 @@ fn print_tree_schedule_by_forester( } } } - } else { - if current_epoch_pda_entry.is_none() { - println!( - "ERROR: Could not find EpochPda for active epoch {}. Cannot check forester assignments.", - current_active_epoch - ); - } + } else if current_epoch_pda_entry.is_none() { + println!( + "ERROR: Could not find EpochPda for active epoch {}. Cannot check forester assignments.", + current_active_epoch + ); } -} \ No newline at end of file +} diff --git a/forester/src/rollover/operations.rs b/forester/src/rollover/operations.rs index bb27db5c02..a7b2d6f493 100644 --- a/forester/src/rollover/operations.rs +++ b/forester/src/rollover/operations.rs @@ -237,10 +237,7 @@ pub async fn is_tree_ready_for_rollover( .await? .unwrap(), ), - _ => panic!( - "is_tree_ready_for_rollover: Invalid tree type {:?}", - tree_type - ), + _ => return Err(ForesterError::InvalidTreeType(tree_type)), }; let is_already_rolled_over = match &account { @@ -262,10 +259,7 @@ pub async fn is_tree_ready_for_rollover( TreeType::AddressV1 => { Ok(tree_info.next_index >= tree_info.threshold && tree_info.next_index > 3) } - _ => panic!( - "is_tree_ready_for_rollover: Invalid tree type {:?}", - tree_type - ), + _ => Err(ForesterError::InvalidTreeType(tree_type)), } } diff --git a/forester/src/send_transaction.rs b/forester/src/send_transaction.rs index 55235d5e2a..3a21dd86f0 100644 --- a/forester/src/send_transaction.rs +++ b/forester/src/send_transaction.rs @@ -11,9 +11,8 @@ use account_compression::utils::constants::{ STATE_MERKLE_TREE_CHANGELOG, STATE_NULLIFIER_QUEUE_VALUES, }; use async_trait::async_trait; -use futures::stream::iter; -use futures::StreamExt; use forester_utils::forester_epoch::TreeAccounts; +use futures::{stream::iter, StreamExt}; use light_client::{ indexer::Indexer, rpc::{RetryConfig, RpcConnection}, @@ -38,7 +37,7 @@ use solana_sdk::{ transaction::Transaction, }; use tokio::{join, sync::Mutex, time::Instant}; -use tracing::{info, warn, debug, error}; +use tracing::{debug, error, info, warn}; use url::Url; use crate::{ @@ -279,7 +278,8 @@ pub async fn send_batched_transactions( work_chunk, config.build_transaction_batch_config, ) - .await { + .await + { Ok(res) => res, Err(e) => { error!(tree = %tree_id_str, "Failed to build transaction batch: {:?}", e); @@ -367,8 +367,7 @@ pub async fn send_batched_transactions( } } Err(ref e) => { - error!(context = %context_str, "Failed to get RPC connection: {:?}", e); - return; + error!(context = %context_str, "Failed to get RPC connection: {:?}", e) } } } @@ -376,7 +375,9 @@ pub async fn send_batched_transactions( info!(tree = %tree_id_str, "Executing batch of {} sends with concurrency limit {}", work_chunk.len(), MAX_CONCURRENT_SENDS); let exec_start = Instant::now(); - send_futures_stream.for_each_concurrent(MAX_CONCURRENT_SENDS, |f| f).await; + send_futures_stream + .for_each_concurrent(MAX_CONCURRENT_SENDS, |f| f) + .await; info!(tree = %tree_id_str, "Finished executing batch in {:?}", exec_start.elapsed()); } diff --git a/sdk-libs/client/src/indexer/photon_indexer.rs b/sdk-libs/client/src/indexer/photon_indexer.rs index bc080ee0d2..63f0cc1f96 100644 --- a/sdk-libs/client/src/indexer/photon_indexer.rs +++ b/sdk-libs/client/src/indexer/photon_indexer.rs @@ -78,10 +78,7 @@ impl PhotonIndexer { &mut self.rpc } - async fn rate_limited_request_with_retry( - &self, - mut operation: F, - ) -> Result + async fn rate_limited_request_with_retry(&self, mut operation: F) -> Result where F: FnMut() -> Fut, Fut: std::future::Future>, @@ -297,6 +294,7 @@ impl Indexer for PhotonIndexer { hashes: Vec, ) -> Result, IndexerError> { self.rate_limited_request_with_retry(|| async { + let hashes_for_async = hashes.clone(); let request: photon_api::models::GetMultipleCompressedAccountProofsPostRequest = @@ -548,12 +546,14 @@ impl Indexer for PhotonIndexer { ) -> Result, IndexerError> { self.rate_limited_request_with_retry(|| async { let request = photon_api::models::GetCompressedTokenAccountsByOwnerPostRequest { - params: Box::new(GetCompressedTokenAccountsByOwnerPostRequestParams { - owner: owner.to_string(), - mint: mint.map(|x| x.to_string()), - cursor: None, - limit: None, - }), + params: Box::new( + GetCompressedTokenAccountsByOwnerPostRequestParams { + owner: owner.to_string(), + mint: mint.map(|x| x.to_string()), + cursor: None, + limit: None, + }, + ), ..Default::default() }; @@ -628,14 +628,14 @@ impl Indexer for PhotonIndexer { hashes: Option>, ) -> Result, IndexerError> { self.rate_limited_request_with_retry(|| async { + let addresses_for_async = addresses.clone(); let hashes_for_async = hashes.clone(); let request = photon_api::models::GetMultipleCompressedAccountsPostRequest { params: Box::new( photon_api::models::GetMultipleCompressedAccountsPostRequestParams { - addresses: addresses_for_async - .map(|x| x.iter().map(|x| x.to_base58()).collect()), + addresses: addresses_for_async.map(|x| x.iter().map(|x| x.to_base58()).collect()), hashes: hashes_for_async.map(|x| x.iter().map(|x| x.to_base58()).collect()), }, ), @@ -661,12 +661,14 @@ impl Indexer for PhotonIndexer { ) -> Result { self.rate_limited_request_with_retry(|| async { let request = photon_api::models::GetCompressedTokenBalancesByOwnerPostRequest { - params: Box::new(GetCompressedTokenAccountsByOwnerPostRequestParams { - owner: owner.to_string(), - mint: mint.map(|x| x.to_string()), - cursor: None, - limit: None, - }), + params: Box::new( + GetCompressedTokenAccountsByOwnerPostRequestParams { + owner: owner.to_string(), + mint: mint.map(|x| x.to_string()), + cursor: None, + limit: None, + }, + ), ..Default::default() }; From 65ea1825075ba43831550a0db4f2725b472c5e65 Mon Sep 17 00:00:00 2001 From: ananas-block <58553958+ananas-block@users.noreply.github.com> Date: Sat, 3 May 2025 23:00:39 +0100 Subject: [PATCH 07/24] fix: forester do not retry failing tx (#1724) * fix: forester do not retry failing tx * cleanup From 772cab01909850264e433b31a4d5c3aaad0635b6 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Sat, 3 May 2025 23:58:16 +0100 Subject: [PATCH 08/24] refactor: enhance error handling and return types in tree scheduling functions --- forester-utils/src/error.rs | 2 + forester-utils/src/forester_epoch.rs | 34 +++++++++------ forester/src/config.rs | 9 +++- forester/src/epoch_manager.rs | 4 +- sdk-libs/client/src/indexer/photon_indexer.rs | 42 +++++++++---------- 5 files changed, 52 insertions(+), 39 deletions(-) diff --git a/forester-utils/src/error.rs b/forester-utils/src/error.rs index 330bfe87ce..caec758b06 100644 --- a/forester-utils/src/error.rs +++ b/forester-utils/src/error.rs @@ -10,4 +10,6 @@ pub enum ForesterUtilsError { Rpc(String), #[error("indexer error: {0:?}")] Indexer(String), + #[error("invalid slot number")] + InvalidSlotNumber, } diff --git a/forester-utils/src/forester_epoch.rs b/forester-utils/src/forester_epoch.rs index 42201a96b4..aa448e0642 100644 --- a/forester-utils/src/forester_epoch.rs +++ b/forester-utils/src/forester_epoch.rs @@ -11,6 +11,8 @@ use light_registry::{ }; use solana_sdk::signature::{Keypair, Signature, Signer}; +use crate::error::ForesterUtilsError; + // What does the forester need to know? // What are my public keys (current epoch account, last epoch account, known Merkle trees) // 1. The current epoch @@ -85,13 +87,13 @@ pub fn get_schedule_for_queue( total_epoch_weight: u64, epoch: u64, current_phase_start_slot: u64, -) -> Vec> { +) -> Result>, ForesterUtilsError> { let mut vec = Vec::new(); let current_light_slot = if start_solana_slot > current_phase_start_slot { (start_solana_slot - current_phase_start_slot) / protocol_config.slot_length } else { - 0 + return Err(ForesterUtilsError::InvalidSlotNumber); }; let start_slot = current_light_slot; @@ -115,7 +117,7 @@ pub fn get_schedule_for_queue( })); start_solana_slot += protocol_config.slot_length; } - vec + Ok(vec) } pub fn get_schedule_for_forester_in_queue( @@ -123,7 +125,7 @@ pub fn get_schedule_for_forester_in_queue( queue_pubkey: &Pubkey, total_epoch_weight: u64, forester_epoch_pda: &ForesterEpochPda, -) -> Vec> { +) -> Result>, ForesterUtilsError> { let mut slots = get_schedule_for_queue( start_solana_slot, queue_pubkey, @@ -131,7 +133,7 @@ pub fn get_schedule_for_forester_in_queue( total_epoch_weight, forester_epoch_pda.epoch, forester_epoch_pda.epoch_active_phase_start_slot, - ); + )?; slots.iter_mut().for_each(|slot_option| { if let Some(slot) = slot_option { if !forester_epoch_pda.is_eligible(slot.forester_index) { @@ -139,7 +141,7 @@ pub fn get_schedule_for_forester_in_queue( } } }); - slots + Ok(slots) } #[derive(Debug, Clone, PartialEq, Eq)] @@ -163,7 +165,7 @@ impl TreeForesterSchedule { solana_slot: u64, forester_epoch_pda: &ForesterEpochPda, epoch_pda: &EpochPda, - ) -> Self { + ) -> Result { let mut _self = Self { tree_accounts: *tree_accounts, slots: Vec::new(), @@ -173,8 +175,8 @@ impl TreeForesterSchedule { &_self.tree_accounts.queue, epoch_pda.registered_weight, forester_epoch_pda, - ); - _self + )?; + Ok(_self) } pub fn is_eligible(&self, forester_slot: u64) -> bool { @@ -398,7 +400,11 @@ impl Epoch { if forester_epoch_pda.total_epoch_weight.is_none() { forester_epoch_pda.total_epoch_weight = Some(epoch_pda.registered_weight); } - self.add_trees_with_schedule(&forester_epoch_pda, &epoch_pda, trees, current_solana_slot); + self.add_trees_with_schedule(&forester_epoch_pda, &epoch_pda, trees, current_solana_slot) + .map_err(|e| { + println!("Error adding trees with schedule: {:?}", e); + RpcError::AssertRpcError("Error adding trees with schedule".to_string()) + })?; Ok(()) } /// Internal function to init Epoch struct with registered account @@ -411,7 +417,7 @@ impl Epoch { epoch_pda: &EpochPda, trees: &[TreeAccounts], current_solana_slot: u64, - ) { + ) -> Result<(), ForesterUtilsError> { // let state = self.phases.get_current_epoch_state(current_solana_slot); // TODO: add epoch state to sync schedule for tree in trees { @@ -420,9 +426,10 @@ impl Epoch { current_solana_slot, forester_epoch_pda, epoch_pda, - ); + )?; self.merkle_trees.push(tree_schedule); } + Ok(()) } pub fn update_state(&mut self, current_solana_slot: u64) -> EpochState { @@ -514,7 +521,8 @@ mod test { total_epoch_weight, epoch, 0, - ); + ) + .unwrap(); assert_eq!( schedule.len(), diff --git a/forester/src/config.rs b/forester/src/config.rs index b848101a85..3a0386a3a8 100644 --- a/forester/src/config.rs +++ b/forester/src/config.rs @@ -261,15 +261,20 @@ pub struct ForesterEpochInfo { } impl ForesterEpochInfo { - pub fn add_trees_with_schedule(&mut self, trees: &[TreeAccounts], current_solana_slot: u64) { + pub fn add_trees_with_schedule( + &mut self, + trees: &[TreeAccounts], + current_solana_slot: u64, + ) -> Result<()> { for tree in trees { let tree_schedule = TreeForesterSchedule::new_with_schedule( tree, current_solana_slot, &self.forester_epoch_pda, &self.epoch_pda, - ); + )?; self.trees.push(tree_schedule); } + Ok(()) } } diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 6dda9faf4a..3ba4ea66e3 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -255,7 +255,7 @@ impl + IndexerType> EpochManager { current_slot, &epoch_info.forester_epoch_pda, &epoch_info.epoch_pda, - ); + )?; epoch_info.trees.push(tree_schedule.clone()); let self_clone = Arc::new(self.clone()); @@ -725,7 +725,7 @@ impl + IndexerType> EpochManager { let slot = rpc.get_slot().await?; let trees = self.trees.lock().await; info!("Adding schedule for trees: {:?}", *trees); - epoch_info.add_trees_with_schedule(&trees, slot); + epoch_info.add_trees_with_schedule(&trees, slot)?; info!("Finished waiting for active phase"); Ok(epoch_info) } diff --git a/sdk-libs/client/src/indexer/photon_indexer.rs b/sdk-libs/client/src/indexer/photon_indexer.rs index 63f0cc1f96..696e8f7c92 100644 --- a/sdk-libs/client/src/indexer/photon_indexer.rs +++ b/sdk-libs/client/src/indexer/photon_indexer.rs @@ -1,5 +1,5 @@ -use std::{fmt::Debug, str::FromStr}; -use std::time::Duration; +use std::{fmt::Debug, str::FromStr, time::Duration}; + use async_trait::async_trait; use light_compressed_account::compressed_account::{ CompressedAccount, CompressedAccountData, CompressedAccountWithMerkleContext, MerkleContext, @@ -78,7 +78,10 @@ impl PhotonIndexer { &mut self.rpc } - async fn rate_limited_request_with_retry(&self, mut operation: F) -> Result + async fn rate_limited_request_with_retry( + &self, + mut operation: F, + ) -> Result where F: FnMut() -> Fut, Fut: std::future::Future>, @@ -294,7 +297,6 @@ impl Indexer for PhotonIndexer { hashes: Vec, ) -> Result, IndexerError> { self.rate_limited_request_with_retry(|| async { - let hashes_for_async = hashes.clone(); let request: photon_api::models::GetMultipleCompressedAccountProofsPostRequest = @@ -546,14 +548,12 @@ impl Indexer for PhotonIndexer { ) -> Result, IndexerError> { self.rate_limited_request_with_retry(|| async { let request = photon_api::models::GetCompressedTokenAccountsByOwnerPostRequest { - params: Box::new( - GetCompressedTokenAccountsByOwnerPostRequestParams { - owner: owner.to_string(), - mint: mint.map(|x| x.to_string()), - cursor: None, - limit: None, - }, - ), + params: Box::new(GetCompressedTokenAccountsByOwnerPostRequestParams { + owner: owner.to_string(), + mint: mint.map(|x| x.to_string()), + cursor: None, + limit: None, + }), ..Default::default() }; @@ -628,14 +628,14 @@ impl Indexer for PhotonIndexer { hashes: Option>, ) -> Result, IndexerError> { self.rate_limited_request_with_retry(|| async { - let addresses_for_async = addresses.clone(); let hashes_for_async = hashes.clone(); let request = photon_api::models::GetMultipleCompressedAccountsPostRequest { params: Box::new( photon_api::models::GetMultipleCompressedAccountsPostRequestParams { - addresses: addresses_for_async.map(|x| x.iter().map(|x| x.to_base58()).collect()), + addresses: addresses_for_async + .map(|x| x.iter().map(|x| x.to_base58()).collect()), hashes: hashes_for_async.map(|x| x.iter().map(|x| x.to_base58()).collect()), }, ), @@ -661,14 +661,12 @@ impl Indexer for PhotonIndexer { ) -> Result { self.rate_limited_request_with_retry(|| async { let request = photon_api::models::GetCompressedTokenBalancesByOwnerPostRequest { - params: Box::new( - GetCompressedTokenAccountsByOwnerPostRequestParams { - owner: owner.to_string(), - mint: mint.map(|x| x.to_string()), - cursor: None, - limit: None, - }, - ), + params: Box::new(GetCompressedTokenAccountsByOwnerPostRequestParams { + owner: owner.to_string(), + mint: mint.map(|x| x.to_string()), + cursor: None, + limit: None, + }), ..Default::default() }; From a3729960e65fd234441e658cec6b4d0811d61d85 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Sun, 4 May 2025 01:20:14 +0100 Subject: [PATCH 09/24] indexer sync for v1 --- forester/src/epoch_manager.rs | 1 + forester/src/send_transaction.rs | 22 +++++++++++++++++++++- 2 files changed, 22 insertions(+), 1 deletion(-) diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 3ba4ea66e3..7adf78423b 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -969,6 +969,7 @@ impl + IndexerType> EpochManager { }; let transaction_builder = EpochManagerTransactions { + pool: self.rpc_pool.clone(), indexer: self.indexer.clone(), epoch: epoch_info.epoch, phantom: std::marker::PhantomData::, diff --git a/forester/src/send_transaction.rs b/forester/src/send_transaction.rs index 3a21dd86f0..1be8cb2c64 100644 --- a/forester/src/send_transaction.rs +++ b/forester/src/send_transaction.rs @@ -11,7 +11,7 @@ use account_compression::utils::constants::{ STATE_MERKLE_TREE_CHANGELOG, STATE_NULLIFIER_QUEUE_VALUES, }; use async_trait::async_trait; -use forester_utils::forester_epoch::TreeAccounts; +use forester_utils::{forester_epoch::TreeAccounts, utils::wait_for_indexer}; use futures::{stream::iter, StreamExt}; use light_client::{ indexer::Indexer, @@ -387,6 +387,7 @@ pub async fn send_batched_transactions( pub struct EpochManagerTransactions> { pub indexer: Arc>, + pub pool: Arc>, pub epoch: u64, pub phantom: std::marker::PhantomData, } @@ -411,6 +412,7 @@ impl> TransactionBuilder for EpochManagerTransac let (_, all_instructions) = fetch_proofs_and_create_instructions( payer.pubkey(), *derivation, + self.pool.clone(), self.indexer.clone(), self.epoch, work_items, @@ -437,6 +439,7 @@ impl> TransactionBuilder for EpochManagerTransac pub async fn fetch_proofs_and_create_instructions>( authority: Pubkey, derivation: Pubkey, + pool: Arc>, indexer: Arc>, epoch: u64, work_items: &[WorkItem], @@ -444,6 +447,23 @@ pub async fn fetch_proofs_and_create_instructions { + debug!("{} Successfully got RPC connection.", context_str); + } + Err(ref e) => { + error!("{} Failed to get RPC connection: {:?}", context_str, e); + } + } + let mut rpc = rpc_result?; + if let Err(e) = wait_for_indexer(&mut *rpc, &*indexer.lock().await).await { + warn!("Error waiting for indexer: {:?}", e); + } + } + let (address_items, state_items): (Vec<_>, Vec<_>) = work_items .iter() .partition(|item| matches!(item.tree_account.tree_type, TreeType::AddressV1)); From 58523218535afa4c38bc3bfa6fee650063e784ef Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Sun, 4 May 2025 15:50:07 +0100 Subject: [PATCH 10/24] update transaction batching configuration for improved performance --- forester/src/epoch_manager.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 7adf78423b..4fe9a1335e 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -950,9 +950,9 @@ impl + IndexerType> EpochManager { ); let batched_tx_config = SendBatchedTransactionsConfig { - num_batches: 1, + num_batches: 2, build_transaction_batch_config: BuildTransactionBatchConfig { - batch_size: 1, + batch_size: 50, compute_unit_price: Some(10_000), compute_unit_limit: Some(300_000), enable_priority_fees: self From b02868fc69e9c897777676947c198c69cbe0c8e2 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Sun, 4 May 2025 16:33:57 +0100 Subject: [PATCH 11/24] refactor: update light slot calculation and add tests for phase start scenarios --- forester-utils/src/forester_epoch.rs | 148 ++++++++++++++++++++++++++- 1 file changed, 146 insertions(+), 2 deletions(-) diff --git a/forester-utils/src/forester_epoch.rs b/forester-utils/src/forester_epoch.rs index aa448e0642..5632e60df9 100644 --- a/forester-utils/src/forester_epoch.rs +++ b/forester-utils/src/forester_epoch.rs @@ -90,7 +90,7 @@ pub fn get_schedule_for_queue( ) -> Result>, ForesterUtilsError> { let mut vec = Vec::new(); - let current_light_slot = if start_solana_slot > current_phase_start_slot { + let current_light_slot = if start_solana_slot >= current_phase_start_slot { (start_solana_slot - current_phase_start_slot) / protocol_config.slot_length } else { return Err(ForesterUtilsError::InvalidSlotNumber); @@ -513,6 +513,7 @@ mod test { let queue_pubkey = Pubkey::new_unique(); let start_solana_slot = 0; let epoch = 0; + let current_phase_start_slot = 0; let schedule = get_schedule_for_queue( start_solana_slot, @@ -520,10 +521,15 @@ mod test { &protocol_config, total_epoch_weight, epoch, - 0, + current_phase_start_slot, ) .unwrap(); + // Expected number of light slots in the active phase + let expected_light_slots = + (protocol_config.active_phase_length / protocol_config.slot_length) as usize; + assert_eq!(schedule.len(), expected_light_slots); // Should generate 100 slots + assert_eq!( schedule.len(), (protocol_config.active_phase_length / protocol_config.slot_length) as usize @@ -543,4 +549,142 @@ mod test { assert!(slot.forester_index < total_epoch_weight); } } + + #[test] + fn test_get_schedule_for_queue_offset_phase_start() { + let protocol_config = ProtocolConfig { + genesis_slot: 1000, // Genesis starts later + min_weight: 100, + slot_length: 10, + registration_phase_length: 100, + active_phase_length: 1000, // 100 light slots + report_work_phase_length: 100, + network_fee: 5000, + ..Default::default() + }; + + let total_epoch_weight = 500; + let queue_pubkey = Pubkey::new_unique(); + let epoch = 0; + + // Calculate actual start of the active phase for epoch 0 + // Registration: 1000 to 1099 + // Active: 1100 to 2099 + let current_phase_start_slot = 1100; + + // Start calculating right from the beginning of this active phase + let start_solana_slot = current_phase_start_slot; + + let schedule = get_schedule_for_queue( + start_solana_slot, + &queue_pubkey, + &protocol_config, + total_epoch_weight, + epoch, + current_phase_start_slot, // Pass the calculated start slot + ) + .unwrap(); + + let expected_light_slots = + (protocol_config.active_phase_length / protocol_config.slot_length) as usize; + assert_eq!(schedule.len(), expected_light_slots); // Still 100 light slots expected + + // Check the first slot details + let first_slot = schedule[0].as_ref().unwrap(); + assert_eq!(first_slot.slot, 0); // First light slot index is 0 + // Its Solana start slot should be the phase start slot + assert_eq!(first_slot.start_solana_slot, current_phase_start_slot); + assert_eq!( + first_slot.end_solana_slot, + current_phase_start_slot + protocol_config.slot_length + ); + + // Check the second slot details + let second_slot = schedule[1].as_ref().unwrap(); + assert_eq!(second_slot.slot, 1); // Second light slot index is 1 + // Its Solana start slot should be offset by one slot_length + assert_eq!( + second_slot.start_solana_slot, + current_phase_start_slot + protocol_config.slot_length + ); + assert_eq!( + second_slot.end_solana_slot, + current_phase_start_slot + 2 * protocol_config.slot_length + ); + } + + // NEW TEST: Case where current_light_slot > 0 + #[test] + fn test_get_schedule_for_queue_mid_phase_start() { + let protocol_config = ProtocolConfig { + genesis_slot: 0, + min_weight: 100, + slot_length: 10, + registration_phase_length: 100, // Reg: 0-99 + active_phase_length: 1000, // Active: 100-1099 (100 light slots) + report_work_phase_length: 100, + network_fee: 5000, + ..Default::default() + }; + + let total_epoch_weight = 500; + let queue_pubkey = Pubkey::new_unique(); + let epoch = 0; + let current_phase_start_slot = 100; // Active phase starts at slot 100 + + // Start calculating from Solana slot 155, which is within the active phase + let start_solana_slot = 155; + + // Calculation: + // current_light_slot = floor((155 - 100) / 10) = floor(55 / 10) = 5 + // Effective start_solana_slot for loop = 100 + (5 * 10) = 150 + // End light slot = 1000 / 10 = 100 + // Loop runs from light_slot 5 to 99 (inclusive). Length = 100 - 5 = 95 + + let schedule = get_schedule_for_queue( + start_solana_slot, + &queue_pubkey, + &protocol_config, + total_epoch_weight, + epoch, + current_phase_start_slot, + ) + .unwrap(); + + let expected_light_slots_total = + protocol_config.active_phase_length / protocol_config.slot_length; // 100 + let expected_start_light_slot = 5; + let expected_schedule_len = + (expected_light_slots_total - expected_start_light_slot) as usize; // 100 - 5 = 95 + + assert_eq!(schedule.len(), expected_schedule_len); // Should generate 95 slots + + // Check the first slot in the *returned* schedule + let first_returned_slot = schedule[0].as_ref().unwrap(); + assert_eq!(first_returned_slot.slot, expected_start_light_slot); // Light slot index starts at 5 + // Its Solana start slot should align to the beginning of light slot 5 + let expected_first_solana_start = + current_phase_start_slot + expected_start_light_slot * protocol_config.slot_length; // 100 + 5 * 10 = 150 + assert_eq!( + first_returned_slot.start_solana_slot, + expected_first_solana_start + ); + assert_eq!( + first_returned_slot.end_solana_slot, + expected_first_solana_start + protocol_config.slot_length // 150 + 10 = 160 + ); + + // Check the second slot in the *returned* schedule + let second_returned_slot = schedule[1].as_ref().unwrap(); + assert_eq!(second_returned_slot.slot, expected_start_light_slot + 1); // Light slot index 6 + // Its Solana start slot should be 160 + assert_eq!( + second_returned_slot.start_solana_slot, + expected_first_solana_start + protocol_config.slot_length + ); + assert_eq!( + second_returned_slot.end_solana_slot, + expected_first_solana_start + 2 * protocol_config.slot_length // 170 + ); + } } From 8b01f63d7b2d552d5c3d493d1a824fdae6d3099e Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Sun, 4 May 2025 17:46:25 +0100 Subject: [PATCH 12/24] refactor: implement rate-limited request for get_indexer_slot method --- sdk-libs/client/src/indexer/photon_indexer.rs | 18 ++++++++++-------- 1 file changed, 10 insertions(+), 8 deletions(-) diff --git a/sdk-libs/client/src/indexer/photon_indexer.rs b/sdk-libs/client/src/indexer/photon_indexer.rs index 696e8f7c92..5b25ca35b3 100644 --- a/sdk-libs/client/src/indexer/photon_indexer.rs +++ b/sdk-libs/client/src/indexer/photon_indexer.rs @@ -894,16 +894,18 @@ impl Indexer for PhotonIndexer { } async fn get_indexer_slot(&self, _r: &mut R) -> Result { - let request = photon_api::models::GetIndexerSlotPostRequest { - ..Default::default() - }; + self.rate_limited_request_with_retry(|| async { + let request = photon_api::models::GetIndexerSlotPostRequest { + ..Default::default() + }; - let result = - photon_api::apis::default_api::get_indexer_slot_post(&self.configuration, request) - .await?; + let result = + photon_api::apis::default_api::get_indexer_slot_post(&self.configuration, request) + .await?; - let result = Self::extract_result("get_indexer_slot", result.result)?; - Ok(result) + let result = Self::extract_result("get_indexer_slot", result.result)?; + Ok(result) + }).await } fn get_address_merkle_trees(&self) -> &Vec { From 73bde7fcd6f28ed22bc32febd0d3094b95e76a56 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Mon, 5 May 2025 00:05:03 +0100 Subject: [PATCH 13/24] refactor: adjust indexer wait logic and enhance error handling in transaction processing --- forester-utils/src/utils.rs | 2 +- forester/src/send_transaction.rs | 102 ++++++++++++------ sdk-libs/client/src/indexer/photon_indexer.rs | 8 +- 3 files changed, 73 insertions(+), 39 deletions(-) diff --git a/forester-utils/src/utils.rs b/forester-utils/src/utils.rs index c4a33d038a..b25cec4a2f 100644 --- a/forester-utils/src/utils.rs +++ b/forester-utils/src/utils.rs @@ -57,7 +57,7 @@ pub async fn wait_for_indexer>( let max_attempts = 20; let mut attempts = 0; - while rpc_slot > indexer_slot { + while rpc_slot > indexer_slot + 20 { if attempts >= max_attempts { return Err(ForesterUtilsError::Indexer( "Maximum attempts reached waiting for indexer to catch up".into(), diff --git a/forester/src/send_transaction.rs b/forester/src/send_transaction.rs index 1be8cb2c64..59f6e1b20f 100644 --- a/forester/src/send_transaction.rs +++ b/forester/src/send_transaction.rs @@ -409,15 +409,27 @@ impl> TransactionBuilder for EpochManagerTransac config: BuildTransactionBatchConfig, ) -> Result<(Vec, u64)> { let mut transactions = vec![]; - let (_, all_instructions) = fetch_proofs_and_create_instructions( + let all_instructions = match fetch_proofs_and_create_instructions( payer.pubkey(), *derivation, self.pool.clone(), self.indexer.clone(), self.epoch, work_items, - ) - .await?; + ).await { + Ok((_, instructions)) => instructions, + Err(e) => { + // Check if it's a "Record Not Found" error + if e.to_string().contains("Record Not Found") { + warn!("Record not found in indexer, skipping batch: {}", e); + // Return empty transactions but don't propagate the error + return Ok((vec![], last_valid_block_height)); + } else { + // For any other error, propagate it + return Err(e); + } + } + }; for instruction in all_instructions { let (transaction, _) = create_smart_transaction(CreateSmartTransactionConfig { @@ -447,28 +459,20 @@ pub async fn fetch_proofs_and_create_instructions { - debug!("{} Successfully got RPC connection.", context_str); - } - Err(ref e) => { - error!("{} Failed to get RPC connection: {:?}", context_str, e); - } - } - let mut rpc = rpc_result?; - if let Err(e) = wait_for_indexer(&mut *rpc, &*indexer.lock().await).await { - warn!("Error waiting for indexer: {:?}", e); - } - } - let (address_items, state_items): (Vec<_>, Vec<_>) = work_items .iter() .partition(|item| matches!(item.tree_account.tree_type, TreeType::AddressV1)); - // Prepare data for batch fetching + for item in state_items.iter() { + if item.tree_account.tree_type != TreeType::StateV1 { + warn!("State item has unexpected tree type: {:?}", item.tree_account.tree_type); + } + } + let state_items = state_items + .into_iter() + .filter(|item| item.tree_account.tree_type == TreeType::StateV1) + .collect::>(); + let address_data = if !address_items.is_empty() { let merkle_tree = address_items .first() @@ -497,16 +501,37 @@ pub async fn fetch_proofs_and_create_instructions proofs, + Err(e) => { + return Err(anyhow::anyhow!("Failed to get address proofs: {}", e)); + } + }; + + let state_proofs = match state_proofs_result { + Ok(proofs) => proofs, + Err(e) => { + return Err(anyhow::anyhow!("Failed to get state proofs: {}", e)); + } + }; - // Process address proofs and create instructions for (item, proof) in address_items.iter().zip(address_proofs.into_iter()) { proofs.push(MerkleProofType::AddressProof(proof.clone())); let instruction = create_update_address_merkle_tree_instruction( diff --git a/sdk-libs/client/src/indexer/photon_indexer.rs b/sdk-libs/client/src/indexer/photon_indexer.rs index 5b25ca35b3..51c82f16ff 100644 --- a/sdk-libs/client/src/indexer/photon_indexer.rs +++ b/sdk-libs/client/src/indexer/photon_indexer.rs @@ -88,8 +88,8 @@ impl PhotonIndexer { { let max_retries = 10; let mut attempts = 0; - let mut delay_ms = 100; - let max_delay_ms = 4000; + let mut delay_ms = 400; + let max_delay_ms = 8000; loop { attempts += 1; @@ -319,7 +319,7 @@ impl Indexer for PhotonIndexer { let error_code = error.code.unwrap_or(0); tracing::error!("API returned error: {}", error_msg); return Err(IndexerError::PhotonError { - context: "get_multiple_new_address_proofs".to_string(), + context: "get_multiple_compressed_account_proofs".to_string(), message: format!("API Error (code {}): {}", error_code, error_msg), }); } @@ -328,7 +328,7 @@ impl Indexer for PhotonIndexer { .result .ok_or_else(|| { IndexerError::missing_result( - "get_multiple_new_address_proofs", + "get_multiple_compressed_account_proofs", "No result returned from Photon API", ) })? From c96f77059ab956ca2a87717cf910d1feb927f385 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Mon, 5 May 2025 14:46:52 +0100 Subject: [PATCH 14/24] refactor: add hash cache into transaction processing --- forester/src/epoch_manager.rs | 23 ++++++---- forester/src/lib.rs | 4 ++ forester/src/send_transaction.rs | 79 ++++++++++++++++++++++++++++++-- 3 files changed, 93 insertions(+), 13 deletions(-) diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 4fe9a1335e..1053db110c 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -45,8 +45,7 @@ use crate::{ queue_helpers::QueueItemData, rollover::is_tree_ready_for_rollover, send_transaction::{ - send_batched_transactions, BuildTransactionBatchConfig, EpochManagerTransactions, - SendBatchedTransactionsConfig, + send_batched_transactions, BuildTransactionBatchConfig, EpochManagerTransactions, ProcessedHashCache, SendBatchedTransactionsConfig }, slot_tracker::{slot_duration, wait_until_slot_reached, SlotTracker}, tree_data_sync::fetch_trees, @@ -94,6 +93,7 @@ pub struct EpochManager> { slot_tracker: Arc, processing_epochs: Arc>>, new_tree_sender: broadcast::Sender, + tx_cache: Arc>, } impl> Clone for EpochManager { @@ -109,6 +109,7 @@ impl> Clone for EpochManager { slot_tracker: self.slot_tracker.clone(), processing_epochs: self.processing_epochs.clone(), new_tree_sender: self.new_tree_sender.clone(), + tx_cache: self.tx_cache.clone(), } } } @@ -124,6 +125,7 @@ impl + IndexerType> EpochManager { trees: Vec, slot_tracker: Arc, new_tree_sender: broadcast::Sender, + tx_cache: Arc>, ) -> Result { Ok(Self { config, @@ -136,6 +138,7 @@ impl + IndexerType> EpochManager { slot_tracker, processing_epochs: Arc::new(DashMap::new()), new_tree_sender, + tx_cache }) } @@ -950,7 +953,7 @@ impl + IndexerType> EpochManager { ); let batched_tx_config = SendBatchedTransactionsConfig { - num_batches: 2, + num_batches: 1, build_transaction_batch_config: BuildTransactionBatchConfig { batch_size: 50, compute_unit_price: Some(10_000), @@ -968,12 +971,12 @@ impl + IndexerType> EpochManager { light_slot_length: epoch_pda.protocol_config.slot_length, }; - let transaction_builder = EpochManagerTransactions { - pool: self.rpc_pool.clone(), - indexer: self.indexer.clone(), - epoch: epoch_info.epoch, - phantom: std::marker::PhantomData::, - }; + let transaction_builder = EpochManagerTransactions::new( + self.indexer.clone(), + self.rpc_pool.clone(), + epoch_info.epoch, + self.tx_cache.clone(), + ); info!( "Attempting to send transactions within slot {:?}", @@ -1342,6 +1345,7 @@ pub async fn run_service + IndexerType>( shutdown: oneshot::Receiver<()>, work_report_sender: mpsc::Sender, slot_tracker: Arc, + tx_cache: Arc>, ) -> Result<()> { info_span!("run_service", forester = %config.payer_keypair.pubkey()) .in_scope(|| async { @@ -1384,6 +1388,7 @@ pub async fn run_service + IndexerType>( trees.clone(), slot_tracker.clone(), new_tree_sender.clone(), + tx_cache.clone(), ) .await { diff --git a/forester/src/lib.rs b/forester/src/lib.rs index c3764368e4..f94e21e6bd 100644 --- a/forester/src/lib.rs +++ b/forester/src/lib.rs @@ -33,6 +33,7 @@ use light_client::{ rpc_pool::SolanaRpcPool, }; use light_compressed_account::TreeType; +use send_transaction::ProcessedHashCache; use solana_sdk::commitment_config::CommitmentConfig; use tokio::sync::{mpsc, oneshot, Mutex}; use tracing::debug; @@ -127,6 +128,8 @@ pub async fn run_pipeline + IndexerType>( SlotTracker::run(arc_slot_tracker_clone, &mut *rpc).await; }); + let tx_cache = Arc::new(Mutex::new(ProcessedHashCache::new(15))); + debug!("Starting Forester pipeline"); run_service( config, @@ -136,6 +139,7 @@ pub async fn run_pipeline + IndexerType>( shutdown, work_report_sender, arc_slot_tracker, + tx_cache, ) .await?; Ok(()) diff --git a/forester/src/send_transaction.rs b/forester/src/send_transaction.rs index 59f6e1b20f..9bad7afbf4 100644 --- a/forester/src/send_transaction.rs +++ b/forester/src/send_transaction.rs @@ -1,9 +1,8 @@ use std::{ - sync::{ + collections::HashMap, sync::{ atomic::{AtomicBool, AtomicUsize, Ordering}, Arc, - }, - vec, + }, time::Duration, vec }; use account_compression::utils::constants::{ @@ -93,6 +92,37 @@ pub struct BuildTransactionBatchConfig { pub enable_priority_fees: bool, } +#[derive(Debug, Clone)] +pub struct ProcessedHashCache { + entries: HashMap, + ttl: Duration, +} + +impl ProcessedHashCache { + pub fn new(ttl_seconds: u64) -> Self { + Self { + entries: HashMap::new(), + ttl: Duration::from_secs(ttl_seconds), + } + } + + fn add(&mut self, hash: &str) { + self.entries.insert(hash.to_string(), Instant::now()); + } + + fn contains(&mut self, hash: &str) -> bool { + self.cleanup(); + self.entries.contains_key(hash) + } + + fn cleanup(&mut self) { + let now = Instant::now(); + self.entries.retain(|_, timestamp| { + now.duration_since(*timestamp) < self.ttl + }); + } +} + /// Calculate the compute unit price in microLamports based on the target lamports and compute units pub fn calculate_compute_unit_price(target_lamports: u64, compute_units: u64) -> u64 { ((target_lamports * 1_000_000) as f64 / compute_units as f64).ceil() as u64 @@ -390,6 +420,19 @@ pub struct EpochManagerTransactions> { pub pool: Arc>, pub epoch: u64, pub phantom: std::marker::PhantomData, + pub processed_hash_cache: Arc>, +} + +impl> EpochManagerTransactions { + pub fn new(indexer: Arc>, pool: Arc>, epoch: u64, cache: Arc>) -> Self { + Self { + indexer, + pool, + epoch, + phantom: std::marker::PhantomData, + processed_hash_cache: cache, //Arc::new(Mutex::new(ProcessedHashCache::new(15))), + } + } } #[async_trait] @@ -408,6 +451,34 @@ impl> TransactionBuilder for EpochManagerTransac work_items: &[WorkItem], config: BuildTransactionBatchConfig, ) -> Result<(Vec, u64)> { + let mut cache = self.processed_hash_cache.lock().await; + + let work_items: Vec<&WorkItem> = work_items + .iter() + .filter(|item| { + let hash_str = bs58::encode(&item.queue_item_data.hash).into_string(); + if cache.contains(&hash_str) { + debug!("Skipping already processed hash: {}", hash_str); + false + } else { + true + } + }) + .collect(); + + for item in &work_items { + let hash_str = bs58::encode(&item.queue_item_data.hash).into_string(); + cache.add(&hash_str); + } + drop(cache); + + if work_items.is_empty() { + debug!("All items in this batch were recently processed, skipping batch"); + return Ok((vec![], last_valid_block_height)); + } + + let work_items = work_items.iter().map(|&item| item.clone()).collect::>(); + let mut transactions = vec![]; let all_instructions = match fetch_proofs_and_create_instructions( payer.pubkey(), @@ -415,7 +486,7 @@ impl> TransactionBuilder for EpochManagerTransac self.pool.clone(), self.indexer.clone(), self.epoch, - work_items, + work_items.as_slice(), ).await { Ok((_, instructions)) => instructions, Err(e) => { From 80c602c34fa1ddd6c3f959ebf93803562759eaa8 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Tue, 6 May 2025 17:45:32 +0100 Subject: [PATCH 15/24] format --- forester/src/epoch_manager.rs | 8 ++- forester/src/send_transaction.rs | 68 +++++++++++++------ sdk-libs/client/src/indexer/photon_indexer.rs | 51 +++++++------- 3 files changed, 77 insertions(+), 50 deletions(-) diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 1053db110c..073b53a946 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -45,7 +45,8 @@ use crate::{ queue_helpers::QueueItemData, rollover::is_tree_ready_for_rollover, send_transaction::{ - send_batched_transactions, BuildTransactionBatchConfig, EpochManagerTransactions, ProcessedHashCache, SendBatchedTransactionsConfig + send_batched_transactions, BuildTransactionBatchConfig, EpochManagerTransactions, + ProcessedHashCache, SendBatchedTransactionsConfig, }, slot_tracker::{slot_duration, wait_until_slot_reached, SlotTracker}, tree_data_sync::fetch_trees, @@ -138,7 +139,7 @@ impl + IndexerType> EpochManager { slot_tracker, processing_epochs: Arc::new(DashMap::new()), new_tree_sender, - tx_cache + tx_cache, }) } @@ -425,7 +426,7 @@ impl + IndexerType> EpochManager { }; debug!("Recovered registration info for epoch {}", epoch); - // Wait for active phase + // Wait for the active phase registration_info = self.wait_for_active_phase(®istration_info).await?; // Perform work @@ -1337,6 +1338,7 @@ fn calculate_remaining_time_or_default( skip(config, protocol_config, rpc_pool, indexer, shutdown, work_report_sender, slot_tracker), fields(forester = %config.payer_keypair.pubkey()) )] +#[allow(clippy::too_many_arguments)] pub async fn run_service + IndexerType>( config: Arc, protocol_config: Arc, diff --git a/forester/src/send_transaction.rs b/forester/src/send_transaction.rs index 9bad7afbf4..b1fbb417bc 100644 --- a/forester/src/send_transaction.rs +++ b/forester/src/send_transaction.rs @@ -1,8 +1,11 @@ use std::{ - collections::HashMap, sync::{ + collections::HashMap, + sync::{ atomic::{AtomicBool, AtomicUsize, Ordering}, Arc, - }, time::Duration, vec + }, + time::Duration, + vec, }; use account_compression::utils::constants::{ @@ -117,9 +120,8 @@ impl ProcessedHashCache { fn cleanup(&mut self) { let now = Instant::now(); - self.entries.retain(|_, timestamp| { - now.duration_since(*timestamp) < self.ttl - }); + self.entries + .retain(|_, timestamp| now.duration_since(*timestamp) < self.ttl); } } @@ -424,7 +426,12 @@ pub struct EpochManagerTransactions> { } impl> EpochManagerTransactions { - pub fn new(indexer: Arc>, pool: Arc>, epoch: u64, cache: Arc>) -> Self { + pub fn new( + indexer: Arc>, + pool: Arc>, + epoch: u64, + cache: Arc>, + ) -> Self { Self { indexer, pool, @@ -465,7 +472,7 @@ impl> TransactionBuilder for EpochManagerTransac } }) .collect(); - + for item in &work_items { let hash_str = bs58::encode(&item.queue_item_data.hash).into_string(); cache.add(&hash_str); @@ -477,8 +484,11 @@ impl> TransactionBuilder for EpochManagerTransac return Ok((vec![], last_valid_block_height)); } - let work_items = work_items.iter().map(|&item| item.clone()).collect::>(); - + let work_items = work_items + .iter() + .map(|&item| item.clone()) + .collect::>(); + let mut transactions = vec![]; let all_instructions = match fetch_proofs_and_create_instructions( payer.pubkey(), @@ -487,18 +497,20 @@ impl> TransactionBuilder for EpochManagerTransac self.indexer.clone(), self.epoch, work_items.as_slice(), - ).await { + ) + .await + { Ok((_, instructions)) => instructions, Err(e) => { // Check if it's a "Record Not Found" error - if e.to_string().contains("Record Not Found") { + return if e.to_string().contains("Record Not Found") { warn!("Record not found in indexer, skipping batch: {}", e); // Return empty transactions but don't propagate the error - return Ok((vec![], last_valid_block_height)); + Ok((vec![], last_valid_block_height)) } else { // For any other error, propagate it - return Err(e); - } + Err(e) + }; } }; @@ -536,7 +548,10 @@ pub async fn fetch_proofs_and_create_instructions proofs, Err(e) => { @@ -736,7 +760,7 @@ pub async fn request_priority_fee_estimate(url: &Url, account_keys: Vec) ) } -/// Get capped priority fee for transaction between min and max. +/// Get a capped priority fee for transaction between min and max. pub fn get_capped_priority_fee(cap_config: CapConfig) -> u64 { if cap_config.max_fee_lamports < cap_config.min_fee_lamports { panic!("Max fee is less than min fee"); diff --git a/sdk-libs/client/src/indexer/photon_indexer.rs b/sdk-libs/client/src/indexer/photon_indexer.rs index 51c82f16ff..a81b4566ea 100644 --- a/sdk-libs/client/src/indexer/photon_indexer.rs +++ b/sdk-libs/client/src/indexer/photon_indexer.rs @@ -865,32 +865,32 @@ impl Indexer for PhotonIndexer { new_addresses_with_trees: Vec, ) -> Result { self.rate_limited_request_with_retry(|| async { - let request = photon_api::models::GetValidityProofV2PostRequest { - params: Box::new(photon_api::models::GetValidityProofPostRequestParams { - hashes: Some(hashes.iter().map(|x| x.to_base58()).collect()), - new_addresses_with_trees: Some( - new_addresses_with_trees - .iter() - .map(|x| photon_api::models::AddressWithTree { - address: x.address.to_base58(), - tree: x.tree.to_string(), - }) - .collect(), - ), - }), - ..Default::default() - }; + let request = photon_api::models::GetValidityProofV2PostRequest { + params: Box::new(photon_api::models::GetValidityProofPostRequestParams { + hashes: Some(hashes.iter().map(|x| x.to_base58()).collect()), + new_addresses_with_trees: Some( + new_addresses_with_trees + .iter() + .map(|x| photon_api::models::AddressWithTree { + address: x.address.to_base58(), + tree: x.tree.to_string(), + }) + .collect(), + ), + }), + ..Default::default() + }; - let result = photon_api::apis::default_api::get_validity_proof_v2_post( - &self.configuration, - request, - ) - .await?; + let result = photon_api::apis::default_api::get_validity_proof_v2_post( + &self.configuration, + request, + ) + .await?; - let result = Self::extract_result("get_validity_proof_v2", result.result)?; - Ok(*result.value) - }) - .await + let result = Self::extract_result("get_validity_proof_v2", result.result)?; + Ok(*result.value) + }) + .await } async fn get_indexer_slot(&self, _r: &mut R) -> Result { @@ -905,7 +905,8 @@ impl Indexer for PhotonIndexer { let result = Self::extract_result("get_indexer_slot", result.result)?; Ok(result) - }).await + }) + .await } fn get_address_merkle_trees(&self) -> &Vec { From 1214cc1ee8336f7b5b626efda43f5339c7828986 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Wed, 7 May 2025 23:51:15 +0100 Subject: [PATCH 16/24] cleanup --- Cargo.lock | 1 - forester/Cargo.toml | 3 +-- forester/src/send_transaction.rs | 4 ++-- forester/tests/e2e_test.rs | 6 +++++- forester/tests/priority_fee_test.rs | 2 +- program-tests/utils/src/e2e_test_env.rs | 4 ++-- 6 files changed, 11 insertions(+), 9 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 66dd51996a..cee954138d 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2239,7 +2239,6 @@ dependencies = [ "tracing", "tracing-appender", "tracing-subscriber", - "url", "warp", ] diff --git a/forester/Cargo.toml b/forester/Cargo.toml index 8f80f86a5f..41c4a3ab94 100644 --- a/forester/Cargo.toml +++ b/forester/Cargo.toml @@ -25,7 +25,6 @@ light-merkle-tree-metadata = { workspace = true } light-sdk = { workspace = true, features = ["anchor"] } light-program-test = { workspace = true } solana-transaction-status = { workspace = true } -url = "2.2" bb8 = { workspace = true } serde_json = "1.0" @@ -56,8 +55,8 @@ serial_test = { workspace = true } light-prover-client = { workspace = true } light-test-utils = { workspace = true } light-program-test = { workspace = true, features = ["devenv"] } +light-batched-merkle-tree = { workspace = true, features = ["test-only"] } dotenvy = "0.15" light-compressed-token = { workspace = true } -light-compressed-account = { workspace = true } rand = { workspace = true } create-address-test-program = { workspace = true } \ No newline at end of file diff --git a/forester/src/send_transaction.rs b/forester/src/send_transaction.rs index b1fbb417bc..c13e7550b0 100644 --- a/forester/src/send_transaction.rs +++ b/forester/src/send_transaction.rs @@ -15,6 +15,7 @@ use account_compression::utils::constants::{ use async_trait::async_trait; use forester_utils::{forester_epoch::TreeAccounts, utils::wait_for_indexer}; use futures::{stream::iter, StreamExt}; +use reqwest::Url; use light_client::{ indexer::Indexer, rpc::{RetryConfig, RpcConnection}, @@ -40,7 +41,6 @@ use solana_sdk::{ }; use tokio::{join, sync::Mutex, time::Instant}; use tracing::{debug, error, info, warn}; -use url::Url; use crate::{ config::QueueConfig, @@ -131,7 +131,7 @@ pub fn calculate_compute_unit_price(target_lamports: u64, compute_units: u64) -> } /// Setting: -/// 1. We have 1 light slot (n solana slots), and elements in thequeue +/// 1. We have 1 light slot (n solana slots), and elements in the queue /// 2. we want to send as many elements from the queue as possible /// /// Strategy: diff --git a/forester/tests/e2e_test.rs b/forester/tests/e2e_test.rs index 78e321b81a..0e33ba317c 100644 --- a/forester/tests/e2e_test.rs +++ b/forester/tests/e2e_test.rs @@ -127,6 +127,7 @@ async fn test_epoch_monitor_with_test_indexer_and_1_forester() { Some(0), ) .await; + // removing batched Merkle tree env.indexer.state_merkle_trees.remove(1); @@ -419,6 +420,9 @@ async fn test_epoch_monitor_with_2_foresters() { let address_tree_with_rollover_threshold_0 = env.indexer.address_merkle_trees[1].accounts.merkle_tree; + println!("State tree with rollover threshold 0: {:?}", state_tree_with_rollover_threshold_0); + println!("Address tree with rollover threshold 0: {:?}", address_tree_with_rollover_threshold_0); + let state_trees: Vec = env .indexer .state_merkle_trees @@ -487,7 +491,7 @@ async fn test_epoch_monitor_with_2_foresters() { )); // Wait for both foresters to report work for epoch 1 - const TIMEOUT_DURATION: Duration = Duration::from_secs(500); + const TIMEOUT_DURATION: Duration = Duration::from_secs(120); const EXPECTED_EPOCHS: u64 = 2; // We expect to process 2 epochs (0 and 1) let result: Result<(), tokio::time::error::Elapsed> = timeout(TIMEOUT_DURATION, async { diff --git a/forester/tests/priority_fee_test.rs b/forester/tests/priority_fee_test.rs index 15ee8cd317..40c14d20ea 100644 --- a/forester/tests/priority_fee_test.rs +++ b/forester/tests/priority_fee_test.rs @@ -1,3 +1,4 @@ +use reqwest::Url; use forester::{ cli::StartArgs, send_transaction::{get_capped_priority_fee, request_priority_fee_estimate, CapConfig}, @@ -5,7 +6,6 @@ use forester::{ }; use light_client::rpc::{RpcConnection, SolanaRpcConnection}; use solana_sdk::{commitment_config::CommitmentConfig, signature::Signer}; -use url::Url; use crate::test_utils::init; mod test_utils; diff --git a/program-tests/utils/src/e2e_test_env.rs b/program-tests/utils/src/e2e_test_env.rs index 81bbe605c2..d6688add28 100644 --- a/program-tests/utils/src/e2e_test_env.rs +++ b/program-tests/utils/src/e2e_test_env.rs @@ -2126,7 +2126,7 @@ where token_accounts = _token_accounts; } let output_merkle_tree_pubkeys = self.get_merkle_tree_pubkeys(1); - let transaction_paramets = if self.keypair_action_config.fee_assert { + let transaction_parameters = if self.keypair_action_config.fee_assert { Some(TransactionParams { num_new_addresses: 0u8, num_input_compressed_accounts: token_accounts.len() as u8, @@ -2143,7 +2143,7 @@ where &mut self.indexer, token_accounts, &output_merkle_tree_pubkeys[0], - transaction_paramets, + transaction_parameters, ) .await; self.stats.spl_frozen += 1; From 1e4a92792614131d261d3e48f7844e0d37b53acb Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Thu, 8 May 2025 19:05:56 +0100 Subject: [PATCH 17/24] cleanup --- forester-utils/src/utils.rs | 2 +- forester/src/epoch_manager.rs | 27 +- forester/src/send_transaction.rs | 95 +------ forester/tests/e2e_test.rs | 386 +++++++--------------------- forester/tests/priority_fee_test.rs | 2 +- sdk-libs/client/src/rpc_pool.rs | 18 +- 6 files changed, 126 insertions(+), 404 deletions(-) diff --git a/forester-utils/src/utils.rs b/forester-utils/src/utils.rs index b25cec4a2f..c4a33d038a 100644 --- a/forester-utils/src/utils.rs +++ b/forester-utils/src/utils.rs @@ -57,7 +57,7 @@ pub async fn wait_for_indexer>( let max_attempts = 20; let mut attempts = 0; - while rpc_slot > indexer_slot + 20 { + while rpc_slot > indexer_slot { if attempts >= max_attempts { return Err(ForesterUtilsError::Indexer( "Maximum attempts reached waiting for indexer to catch up".into(), diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 073b53a946..6dc6113a14 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -7,7 +7,7 @@ use std::{ time::Duration, }; -use anyhow::Context; +use anyhow::{anyhow, Context}; use dashmap::DashMap; use forester_utils::forester_epoch::{get_epoch_phases, Epoch, TreeAccounts, TreeForesterSchedule}; use futures::future::join_all; @@ -940,7 +940,7 @@ impl + IndexerType> EpochManager { if tree.tree_accounts.tree_type == TreeType::StateV1 || tree.tree_accounts.tree_type == TreeType::AddressV1 { - let transaction_timeout_buffer = Duration::from_secs(60); + let transaction_timeout_buffer = Duration::ZERO; let remaining_time_timeout = calculate_remaining_time_or_default( estimated_slot, @@ -1009,20 +1009,6 @@ impl + IndexerType> EpochManager { ) .await; items_processed_this_iteration = num_sent; - - trace!( - "Checking for rollover readiness after processing batch..." - ); - if let Err(e) = - self.rollover_if_needed(&tree.tree_accounts).await - { - error!( - "Rollover check failed during slot processing: {:?}", - e - ); - } else { - trace!("Rollover check completed."); - } } else { info!("send_batched_transactions processed 0 items. Queue likely empty for this attempt."); } @@ -1035,6 +1021,10 @@ impl + IndexerType> EpochManager { iteration_failed = true; } } + + if let Err(e) = self.rollover_if_needed(&tree.tree_accounts).await { + error!("Rollover check failed during slot processing: {:?}", e); + } } else if tree.tree_accounts.tree_type == TreeType::StateV2 || tree.tree_accounts.tree_type == TreeType::AddressV2 { @@ -1294,10 +1284,7 @@ impl + IndexerType> EpochManager { ) .await } - _ => panic!( - "perform rollover: Invalid tree type {:?}", - tree_account.tree_type - ), + _ => Err(ForesterError::InvalidTreeType(tree_account.tree_type)), }; match result { diff --git a/forester/src/send_transaction.rs b/forester/src/send_transaction.rs index c13e7550b0..f84d2265ac 100644 --- a/forester/src/send_transaction.rs +++ b/forester/src/send_transaction.rs @@ -15,7 +15,6 @@ use account_compression::utils::constants::{ use async_trait::async_trait; use forester_utils::{forester_epoch::TreeAccounts, utils::wait_for_indexer}; use futures::{stream::iter, StreamExt}; -use reqwest::Url; use light_client::{ indexer::Indexer, rpc::{RetryConfig, RpcConnection}, @@ -29,6 +28,7 @@ use light_registry::{ }, utils::get_forester_epoch_pda_from_authority, }; +use reqwest::Url; use solana_client::rpc_config::RpcSendTransactionConfig; use solana_sdk::{ bs58, @@ -189,21 +189,7 @@ pub async fn send_batched_transactions( }; let queue_item_data = { - let context_str = format!( - "send_batched_transactions (fetch_queue_item_data), tree: {}", - tree_accounts.merkle_tree - ); - debug!("{} Attempting to get RPC connection...", context_str); - let rpc_result = pool.get_connection().await; - match rpc_result { - Ok(_) => { - debug!("{} Successfully got RPC connection.", context_str); - } - Err(ref e) => { - error!("{} Failed to get RPC connection: {:?}", context_str, e); - } - } - let mut rpc = rpc_result?; + let mut rpc = pool.get_connection().await?; fetch_queue_item_data( &mut *rpc, @@ -221,22 +207,7 @@ pub async fn send_batched_transactions( } let (recent_blockhash, current_block_height) = { - let context_str = format!( - "send_batched_transactions (blockhash/height), tree: {}", - tree_id_str - ); - debug!("{} Attempting to get RPC connection...", context_str); - let rpc_result = pool.get_connection().await; - match rpc_result { - Ok(_) => { - debug!("{} Successfully got RPC connection.", context_str); - } - Err(ref e) => { - error!("{} Failed to get RPC connection: {:?}", context_str, e); - } - } - let mut rpc = rpc_result?; - + let mut rpc = pool.get_connection().await?; ( rpc.get_latest_blockhash().await?, rpc.get_block_height().await?, @@ -245,22 +216,7 @@ pub async fn send_batched_transactions( let last_valid_block_height = current_block_height + 150; let priority_fee = if config.build_transaction_batch_config.enable_priority_fees { - let context_str = format!( - "send_batched_transactions (priority_fee), tree: {}", - tree_accounts.merkle_tree - ); - debug!("{} Attempting to get RPC connection...", context_str); - let rpc_result = pool.get_connection().await; - match rpc_result { - Ok(_) => { - debug!("{} Successfully got RPC connection.", context_str); - } - Err(ref e) => { - error!("{} Failed to get RPC connection: {:?}", context_str, e); - } - } - let rpc = rpc_result?; - + let rpc = pool.get_connection().await?; let forester_epoch_pda_pubkey = get_forester_epoch_pda_from_authority(derivation, transaction_builder.epoch()).0; @@ -291,7 +247,7 @@ pub async fn send_batched_transactions( for work_chunk in work_items.chunks(config.build_transaction_batch_config.batch_size as usize) { if cancel_signal.load(Ordering::SeqCst) { - info!(tree = %tree_id_str, "Cancellation signal received, stopping batch processing."); + debug!(tree = %tree_id_str, "Cancellation signal received, stopping batch processing."); break; } if Instant::now() >= timeout_deadline { @@ -354,12 +310,9 @@ pub async fn send_batched_transactions( let tx_signature_str = tx_signature.to_string(); let context_str = format!("send_batched_transactions (concurrent sender), tree: {}, tx_sig_prefix: {}", tree_id_str_clone, &tx_signature_str[..8]); - debug!(context = %context_str, "Attempting to get RPC connection..."); let rpc_result = pool_clone.get_connection().await; - match rpc_result { Ok(mut rpc) => { - debug!(context = %context_str, "Successfully got RPC connection."); if Instant::now() >= deadline { warn!(context = %context_str, "Reached timeout deadline after getting connection, skipping send"); return; @@ -371,15 +324,12 @@ pub async fn send_batched_transactions( match result { Ok(signature) => { num_sent_transactions_clone.fetch_add(1, Ordering::SeqCst); - info!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %signature, "Transaction sent successfully"); + debug!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %signature, "Transaction sent successfully"); } Err(e) => { warn!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %tx_signature_str, "Transaction send/process failed: {:?}", e); - let retry_check_context = format!("send_batched_transactions (retry check), tree: {}", tree_id_str_clone); - debug!(context = %retry_check_context, "Attempting RPC connection for retry check..."); match pool_clone.get_connection().await { Ok(check_rpc) => { - debug!(context = %retry_check_context, "Got RPC connection for retry check."); if !check_rpc.should_retry(&e) { warn!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %tx_signature_str, "Non-retryable RPC error detected, setting cancel signal: {:?}", e); cancel_signal_clone.store(true, Ordering::SeqCst); @@ -405,15 +355,15 @@ pub async fn send_batched_transactions( } }); - info!(tree = %tree_id_str, "Executing batch of {} sends with concurrency limit {}", work_chunk.len(), MAX_CONCURRENT_SENDS); + debug!(tree = %tree_id_str, "Executing batch of {} sends with concurrency limit {}", work_chunk.len(), MAX_CONCURRENT_SENDS); let exec_start = Instant::now(); send_futures_stream .for_each_concurrent(MAX_CONCURRENT_SENDS, |f| f) .await; - info!(tree = %tree_id_str, "Finished executing batch in {:?}", exec_start.elapsed()); + debug!(tree = %tree_id_str, "Finished executing batch in {:?}", exec_start.elapsed()); } - info!(tree = %tree_id_str, "Transaction sending loop finished. Total transactions sent attempt count: {}", num_sent_transactions.load(Ordering::Relaxed)); + debug!(tree = %tree_id_str, "Transaction sending loop finished. Total transactions sent attempt count: {}", num_sent_transactions.load(Ordering::Relaxed)); Ok(num_sent_transactions.load(Ordering::SeqCst)) } @@ -437,7 +387,7 @@ impl> EpochManagerTransactions { pool, epoch, phantom: std::marker::PhantomData, - processed_hash_cache: cache, //Arc::new(Mutex::new(ProcessedHashCache::new(15))), + processed_hash_cache: cache, } } } @@ -587,32 +537,10 @@ pub async fn fetch_proofs_and_create_instructions::new( - config.external_services.rpc_url.to_string(), - CommitmentConfig::confirmed(), - config.general_config.rpc_pool_size as u32, - None, - None, - ) - .await - .unwrap(); - - let mut rpc = SolanaRpcConnection::new(SolanaRpcUrl::Localnet, None); - rpc.payer = forester_keypair.insecure_clone(); - - rpc.airdrop_lamports(&forester_keypair.pubkey(), LAMPORTS_PER_SOL * 100_000) - .await - .unwrap(); - - rpc.airdrop_lamports( - &env_accounts.governance_authority.pubkey(), - LAMPORTS_PER_SOL * 100_000, - ) - .await - .unwrap(); - - register_test_forester( - &mut rpc, - &env_accounts.governance_authority, - &forester_keypair.pubkey(), - light_registry::ForesterConfig::default(), - ) - .await - .unwrap(); - - let new_forester_keypair = Keypair::new(); - rpc.airdrop_lamports(&new_forester_keypair.pubkey(), LAMPORTS_PER_SOL * 100_000) - .await - .unwrap(); - - update_test_forester( - &mut rpc, - &forester_keypair, - &forester_keypair.pubkey(), - Some(&new_forester_keypair), - light_registry::ForesterConfig::default(), - ) - .await - .unwrap(); - - config.derivation_pubkey = forester_keypair.pubkey(); - config.payer_keypair = new_forester_keypair.insecure_clone(); - - let config = Arc::new(config); - let indexer: TestIndexer = - TestIndexer::init_from_env(&config.payer_keypair, &env_accounts, None).await; - - let mut env = E2ETestEnv::>::new( - rpc, - indexer, - &env_accounts, - keypair_action_config(), - general_action_config(), - 0, - Some(0), - ) - .await; - - // removing batched Merkle tree - env.indexer.state_merkle_trees.remove(1); - - let user_index = 0; - let balance = env - .rpc - .get_balance(&env.users[user_index].keypair.pubkey()) - .await - .unwrap(); - env.compress_sol(user_index, balance).await; - let state_trees: Vec = env - .indexer - .state_merkle_trees - .iter() - .map(|x| x.accounts) - .collect(); - let address_trees: Vec = env - .indexer - .address_merkle_trees - .iter() - .map(|x| x.accounts) - .collect(); - - let iterations = 1; - let mut total_expected_work = 0; - // Create work and assert that the queues are not empty - { - for _ in 0..iterations { - env.transfer_sol(user_index).await; - env.create_address(None, None).await; - } - - // Asserting non-empty because transfer sol is not deterministic. - assert_queue_len( - &pool, - &state_trees, - &address_trees, - &mut total_expected_work, - iterations, - true, - ) - .await; - } - - let (shutdown_sender, shutdown_receiver) = oneshot::channel(); - let (work_report_sender, mut work_report_receiver) = mpsc::channel(100); - - // Run the forester as pipeline - let service_handle = tokio::spawn(run_pipeline( - config.clone(), - None, - None, - Arc::new(Mutex::new(env.indexer)), - shutdown_receiver, - work_report_sender, - )); - - if work_report_receiver.recv().await.is_some() { - println!("work_reported"); - }; - let mut rpc = pool.get_connection().await.unwrap(); - let epoch_pda_address = get_epoch_pda_address(0); - let epoch_pda = (*rpc) - .get_anchor_account::(&epoch_pda_address) - .await - .unwrap() - .unwrap(); - let total_processed = epoch_pda.total_work; - - let forester_epoch_pda_address = - get_forester_epoch_pda_from_authority(&config.derivation_pubkey, 0).0; - let forester_epoch_pda = (*rpc) - .get_anchor_account::(&forester_epoch_pda_address) - .await - .unwrap() - .unwrap(); - - assert_eq!(forester_epoch_pda.work_counter, total_processed); - - // assert that all (2) queues have been emptied - { - assert_queue_len( - &pool, - &state_trees.clone(), - &address_trees.clone(), - &mut 0, - 0, - false, - ) - .await; - - assert_eq!( - total_processed, total_expected_work, - "Not all items were processed." - ); - } - shutdown_sender - .send(()) - .expect("Failed to send shutdown signal"); - service_handle.await.unwrap().unwrap(); -} - -pub async fn assert_queue_len( - pool: &SolanaRpcPool, - state_trees: &[StateMerkleTreeAccounts], - address_trees: &[AddressMerkleTreeAccounts], - total_expected_work: &mut u64, - expected_len: usize, - not_empty: bool, -) { - for tree in state_trees.iter() { - let mut rpc = pool.get_connection().await.unwrap(); - let queue_length = fetch_queue_item_data( - &mut *rpc, - &tree.nullifier_queue, - 0, - STATE_NULLIFIER_QUEUE_VALUES, - STATE_NULLIFIER_QUEUE_VALUES, - ) - .await - .unwrap() - .len(); - if not_empty { - assert_ne!(queue_length, 0); - } else { - assert_eq!(queue_length, expected_len); - } - *total_expected_work += queue_length as u64; - } - - for tree in address_trees.iter() { - let mut rpc = pool.get_connection().await.unwrap(); - let queue_length = fetch_queue_item_data( - &mut *rpc, - &tree.queue, - 0, - ADDRESS_QUEUE_VALUES, - ADDRESS_QUEUE_VALUES, - ) - .await - .unwrap() - .len(); - if not_empty { - assert_ne!(queue_length, 0); - } else { - assert_eq!(queue_length, expected_len); - } - *total_expected_work += queue_length as u64; - } -} - -// TODO: extend test to 3 epochs (epoch 0 is skipped for 40s wait time) -// TODO: add test which asserts epoch registration over many epochs (we need a different protocol config for that) -// TODO: add test with photon indexer for an infinite local test which performs work over many epochs #[serial] #[tokio::test(flavor = "multi_thread", worker_threads = 32)] async fn test_epoch_monitor_with_2_foresters() { @@ -420,8 +168,14 @@ async fn test_epoch_monitor_with_2_foresters() { let address_tree_with_rollover_threshold_0 = env.indexer.address_merkle_trees[1].accounts.merkle_tree; - println!("State tree with rollover threshold 0: {:?}", state_tree_with_rollover_threshold_0); - println!("Address tree with rollover threshold 0: {:?}", address_tree_with_rollover_threshold_0); + println!( + "State tree with rollover threshold 0: {:?}", + state_tree_with_rollover_threshold_0 + ); + println!( + "Address tree with rollover threshold 0: {:?}", + address_tree_with_rollover_threshold_0 + ); let state_trees: Vec = env .indexer @@ -490,50 +244,40 @@ async fn test_epoch_monitor_with_2_foresters() { work_report_sender2, )); - // Wait for both foresters to report work for epoch 1 - const TIMEOUT_DURATION: Duration = Duration::from_secs(120); - const EXPECTED_EPOCHS: u64 = 2; // We expect to process 2 epochs (0 and 1) - - let result: Result<(), tokio::time::error::Elapsed> = timeout(TIMEOUT_DURATION, async { - let mut processed_epochs = HashSet::new(); - let mut total_processed = 0; - while processed_epochs.len() < EXPECTED_EPOCHS as usize { - tokio::select! { - Some(report) = work_report_receiver1.recv() => { - println!("Received work report from forester 1: {:?}", report); - total_processed += report.processed_items; - processed_epochs.insert(report.epoch); - } - Some(report) = work_report_receiver2.recv() => { - println!("Received work report from forester 2: {:?}", report); - total_processed += report.processed_items; - processed_epochs.insert(report.epoch); - } - else => break, + const EXPECTED_EPOCHS: u64 = 3; // We expect to process 2 epochs (0 and 1) + + let mut processed_epochs = HashSet::new(); + let mut total_processed = 0; + while processed_epochs.len() < EXPECTED_EPOCHS as usize { + tokio::select! { + Some(report) = work_report_receiver1.recv() => { + println!("Received work report from forester 1: {:?}", report); + total_processed += report.processed_items; + processed_epochs.insert(report.epoch); } + Some(report) = work_report_receiver2.recv() => { + println!("Received work report from forester 2: {:?}", report); + total_processed += report.processed_items; + processed_epochs.insert(report.epoch); + } + else => break, } + } - println!("Processed {} items", total_processed); - - // Verify that we've processed the expected number of epochs - assert_eq!( - processed_epochs.len(), - EXPECTED_EPOCHS as usize, - "Processed {} epochs, expected {}", - processed_epochs.len(), - EXPECTED_EPOCHS - ); - - // Verify that we've processed epochs 0 and 1 - // assert!(processed_epochs.contains(&0), "Epoch 0 was not processed"); - assert!(processed_epochs.contains(&1), "Epoch 1 was not processed"); - }) - .await; + println!("Processed {} items", total_processed); - // Handle timeout - if result.is_err() { - panic!("Test timed out after {:?}", TIMEOUT_DURATION); - } + // Verify that we've processed the expected number of epochs + assert_eq!( + processed_epochs.len(), + EXPECTED_EPOCHS as usize, + "Processed {} epochs, expected {}", + processed_epochs.len(), + EXPECTED_EPOCHS + ); + + // Verify that we've processed epochs 0 and 1 + // assert!(processed_epochs.contains(&0), "Epoch 0 was not processed"); + assert!(processed_epochs.contains(&1), "Epoch 1 was not processed"); assert_trees_are_rolledover( &pool, @@ -607,6 +351,7 @@ pub async fn assert_trees_are_rolledover( state_merkle_tree ); } + async fn assert_foresters_registered( foresters: &[Pubkey], rpc: &mut SolanaRpcConnection, @@ -773,3 +518,52 @@ async fn test_epoch_double_registration() { "Registered epoch should match current epoch" ); } + +pub async fn assert_queue_len( + pool: &SolanaRpcPool, + state_trees: &[StateMerkleTreeAccounts], + address_trees: &[AddressMerkleTreeAccounts], + total_expected_work: &mut u64, + expected_len: usize, + not_empty: bool, +) { + for tree in state_trees.iter() { + let mut rpc = pool.get_connection().await.unwrap(); + let queue_length = fetch_queue_item_data( + &mut *rpc, + &tree.nullifier_queue, + 0, + STATE_NULLIFIER_QUEUE_VALUES, + STATE_NULLIFIER_QUEUE_VALUES, + ) + .await + .unwrap() + .len(); + if not_empty { + assert_ne!(queue_length, 0); + } else { + assert_eq!(queue_length, expected_len); + } + *total_expected_work += queue_length as u64; + } + + for tree in address_trees.iter() { + let mut rpc = pool.get_connection().await.unwrap(); + let queue_length = fetch_queue_item_data( + &mut *rpc, + &tree.queue, + 0, + ADDRESS_QUEUE_VALUES, + ADDRESS_QUEUE_VALUES, + ) + .await + .unwrap() + .len(); + if not_empty { + assert_ne!(queue_length, 0); + } else { + assert_eq!(queue_length, expected_len); + } + *total_expected_work += queue_length as u64; + } +} diff --git a/forester/tests/priority_fee_test.rs b/forester/tests/priority_fee_test.rs index 40c14d20ea..19a313c3df 100644 --- a/forester/tests/priority_fee_test.rs +++ b/forester/tests/priority_fee_test.rs @@ -1,10 +1,10 @@ -use reqwest::Url; use forester::{ cli::StartArgs, send_transaction::{get_capped_priority_fee, request_priority_fee_estimate, CapConfig}, ForesterConfig, }; use light_client::rpc::{RpcConnection, SolanaRpcConnection}; +use reqwest::Url; use solana_sdk::{commitment_config::CommitmentConfig, signature::Signer}; use crate::test_utils::init; diff --git a/sdk-libs/client/src/rpc_pool.rs b/sdk-libs/client/src/rpc_pool.rs index 83319c8089..07f7c505a7 100644 --- a/sdk-libs/client/src/rpc_pool.rs +++ b/sdk-libs/client/src/rpc_pool.rs @@ -5,6 +5,7 @@ use bb8::{Pool, PooledConnection}; use solana_sdk::commitment_config::CommitmentConfig; use thiserror::Error; use tokio::time::sleep; +use tracing::{debug, error}; use crate::{ rate_limiter::RateLimiter, @@ -100,10 +101,23 @@ impl SolanaRpcPool { pub async fn get_connection( &self, ) -> Result>, PoolError> { - self.pool + debug!("Attempting to get RPC connection..."); + let result = self + .pool .get() .await - .map_err(|e| PoolError::Pool(e.to_string())) + .map_err(|e| PoolError::Pool(e.to_string())); + + match result { + Ok(_) => { + debug!("Successfully got RPC connection"); + } + Err(ref e) => { + error!("Failed to get RPC connection: {:?}", e); + } + } + + result } pub async fn get_connection_with_retry( From 2847579db58f4abfcff7e7336856a94d915079ac Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Fri, 9 May 2025 00:23:15 +0100 Subject: [PATCH 18/24] refactor tree processing --- examples/anchor/token-escrow/tests/test.rs | 4 +- .../token-escrow/tests/test_compressed_pda.rs | 4 +- forester-utils/src/utils.rs | 2 +- forester/src/epoch_manager.rs | 598 +++++++-------- forester/src/errors.rs | 6 +- forester/src/lib.rs | 5 +- forester/src/processor/mod.rs | 3 + forester/src/processor/tx_cache.rs | 33 + forester/src/processor/v1/config.rs | 29 + forester/src/processor/v1/helpers.rs | 259 +++++++ forester/src/processor/v1/mod.rs | 4 + forester/src/processor/v1/send_transaction.rs | 373 ++++++++++ forester/src/processor/v1/tx_builder.rs | 151 ++++ .../v2}/address.rs | 10 +- .../v2}/common.rs | 16 +- .../v2}/error.rs | 0 .../{batch_processor => processor/v2}/mod.rs | 4 +- .../v2}/state.rs | 16 +- forester/src/rollover/operations.rs | 10 +- forester/src/send_transaction.rs | 702 ------------------ forester/tests/priority_fee_test.rs | 5 +- .../compressed-token-test/tests/test.rs | 2 +- program-tests/system-cpi-test/tests/test.rs | 2 +- .../tests/test_program_owned_trees.rs | 6 +- program-tests/system-test/tests/test.rs | 12 +- program-tests/utils/src/address.rs | 4 +- .../utils/src/address_tree_rollover.rs | 12 +- .../utils/src/state_tree_rollover.rs | 4 +- sdk-libs/client/src/rpc/rpc_connection.rs | 6 +- sdk-libs/client/src/rpc/solana_rpc.rs | 3 +- .../program-test/src/test_batch_forester.rs | 2 +- sdk-libs/program-test/src/test_env.rs | 39 +- sdk-libs/program-test/src/test_rpc.rs | 5 +- xtask/src/new_deployment.rs | 2 +- 34 files changed, 1224 insertions(+), 1109 deletions(-) create mode 100644 forester/src/processor/mod.rs create mode 100644 forester/src/processor/tx_cache.rs create mode 100644 forester/src/processor/v1/config.rs create mode 100644 forester/src/processor/v1/helpers.rs create mode 100644 forester/src/processor/v1/mod.rs create mode 100644 forester/src/processor/v1/send_transaction.rs create mode 100644 forester/src/processor/v1/tx_builder.rs rename forester/src/{batch_processor => processor/v2}/address.rs (94%) rename forester/src/{batch_processor => processor/v2}/common.rs (97%) rename forester/src/{batch_processor => processor/v2}/error.rs (100%) rename forester/src/{batch_processor => processor/v2}/mod.rs (90%) rename forester/src/{batch_processor => processor/v2}/state.rs (94%) delete mode 100644 forester/src/send_transaction.rs diff --git a/examples/anchor/token-escrow/tests/test.rs b/examples/anchor/token-escrow/tests/test.rs index e114d07ba8..56cf52b48d 100644 --- a/examples/anchor/token-escrow/tests/test.rs +++ b/examples/anchor/token-escrow/tests/test.rs @@ -329,7 +329,7 @@ pub async fn perform_escrow_failing + TestIndexe &[instruction], Some(&payer.pubkey()), &[&payer], - rpc.get_latest_blockhash().await.unwrap(), + rpc.get_latest_blockhash().await.unwrap().0, ); rpc.process_transaction(transaction).await } @@ -499,7 +499,7 @@ pub async fn perform_withdrawal_failing< &[instruction], Some(&payer.pubkey()), &[&payer], - rpc.get_latest_blockhash().await.unwrap(), + rpc.get_latest_blockhash().await.unwrap().0, ); rpc.process_transaction(transaction).await } diff --git a/examples/anchor/token-escrow/tests/test_compressed_pda.rs b/examples/anchor/token-escrow/tests/test_compressed_pda.rs index 62c2184559..4d6dccdc76 100644 --- a/examples/anchor/token-escrow/tests/test_compressed_pda.rs +++ b/examples/anchor/token-escrow/tests/test_compressed_pda.rs @@ -167,7 +167,7 @@ pub async fn perform_escrow_failing( escrow_amount, ) .await; - let latest_blockhash = rpc.get_latest_blockhash().await.unwrap(); + let latest_blockhash = rpc.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&payer_pubkey), @@ -410,7 +410,7 @@ pub async fn perform_withdrawal_failing( escrow_amount, ) .await; - let latest_blockhash = rpc.get_latest_blockhash().await.unwrap(); + let latest_blockhash = rpc.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&payer.pubkey()), diff --git a/forester-utils/src/utils.rs b/forester-utils/src/utils.rs index c4a33d038a..5f281069ae 100644 --- a/forester-utils/src/utils.rs +++ b/forester-utils/src/utils.rs @@ -27,7 +27,7 @@ pub async fn airdrop_lamports( &[transfer_instruction], Some(&rpc.get_payer().pubkey()), &vec![&rpc.get_payer()], - latest_blockhash, + latest_blockhash.0, ); rpc.process_transaction(transaction).await?; Ok(()) diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 6dc6113a14..84e8d5e273 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -9,7 +9,9 @@ use std::{ use anyhow::{anyhow, Context}; use dashmap::DashMap; -use forester_utils::forester_epoch::{get_epoch_phases, Epoch, TreeAccounts, TreeForesterSchedule}; +use forester_utils::forester_epoch::{ + get_epoch_phases, Epoch, ForesterSlot, TreeAccounts, TreeForesterSchedule, +}; use futures::future::join_all; use light_client::{ indexer::{Indexer, MerkleProof, NewAddressProofWithContext}, @@ -35,19 +37,23 @@ use tokio::{ use tracing::{debug, error, info, info_span, instrument, trace, warn}; use crate::{ - batch_processor::{process_batched_operations, BatchContext}, errors::{ ChannelError, ForesterError, InitializationError, RegistrationError, WorkReportError, }, indexer_type::{rollover_address_merkle_tree, rollover_state_merkle_tree, IndexerType}, metrics::{push_metrics, queue_metric_update, update_forester_sol_balance}, pagerduty::send_pagerduty_alert, + processor::{ + tx_cache::ProcessedHashCache, + v1::{ + config::{BuildTransactionBatchConfig, SendBatchedTransactionsConfig}, + send_transaction::send_batched_transactions, + tx_builder::EpochManagerTransactions, + }, + v2::{process_batched_operations, BatchContext}, + }, queue_helpers::QueueItemData, rollover::is_tree_ready_for_rollover, - send_transaction::{ - send_batched_transactions, BuildTransactionBatchConfig, EpochManagerTransactions, - ProcessedHashCache, SendBatchedTransactionsConfig, - }, slot_tracker::{slot_duration, wait_until_slot_reached, SlotTracker}, tree_data_sync::fetch_trees, tree_finder::TreeFinder, @@ -615,8 +621,7 @@ impl + IndexerType> EpochManager { trees: Vec::new(), } }; - debug!("Registration for epoch completed"); - debug!("Registration Info: {:?}", registration_info); + debug!("Registered: {:?}", registration_info); Ok(registration_info) } else { warn!( @@ -728,7 +733,7 @@ impl + IndexerType> EpochManager { let slot = rpc.get_slot().await?; let trees = self.trees.lock().await; - info!("Adding schedule for trees: {:?}", *trees); + trace!("Adding schedule for trees: {:?}", *trees); epoch_info.add_trees_with_schedule(&trees, slot)?; info!("Finished waiting for active phase"); Ok(epoch_info) @@ -760,7 +765,7 @@ impl + IndexerType> EpochManager { let mut handles: Vec>> = Vec::new(); for tree in epoch_info.trees.iter() { - info!( + trace!( "Creating thread for tree {}", tree.tree_accounts.merkle_tree ); @@ -780,7 +785,7 @@ impl + IndexerType> EpochManager { handles.push(handle); } - debug!("Threads created. Waiting for active phase to end"); + trace!("Threads created. Waiting for active phase to end"); // Wait for all tasks to complete for result in join_all(handles).await { @@ -796,8 +801,6 @@ impl + IndexerType> EpochManager { debug!("Waiting for active phase to end"); let mut rpc = self.rpc_pool.get_connection().await?; wait_until_slot_reached(&mut *rpc, &self.slot_tracker, active_phase_end).await?; - - info!("Completed active work"); Ok(()) } @@ -810,338 +813,312 @@ impl + IndexerType> EpochManager { #[instrument( level = "debug", - skip(self, epoch_info, epoch_pda, tree), + skip(self, epoch_info, epoch_pda, tree_schedule), fields(forester = %self.config.payer_keypair.pubkey(), epoch = epoch_info.epoch, - tree = %tree.tree_accounts.merkle_tree) + tree = %tree_schedule.tree_accounts.merkle_tree) )] pub async fn process_queue( &self, epoch_info: &Epoch, epoch_pda: &ForesterEpochPda, - mut tree: TreeForesterSchedule, + mut tree_schedule: TreeForesterSchedule, ) -> Result<()> { info!("enter process_queue"); - - let mut estimated_slot = self.slot_tracker.estimated_current_slot(); - - trace!( - "Estimated slot: {}, epoch end: {}", - estimated_slot, - epoch_info.phases.active.end - ); - 'outer: while estimated_slot < epoch_info.phases.active.end { - let index_and_forester_slot = tree + let mut current_slot = self.slot_tracker.estimated_current_slot(); + 'outer_slot_loop: while current_slot < epoch_info.phases.active.end { + let next_slot_to_process = tree_schedule .slots - .iter() + .iter_mut() .enumerate() - .find(|(_, slot)| slot.is_some()); - - if let Some((slot_index, forester_slot)) = index_and_forester_slot { - let forester_slot = forester_slot.as_ref().unwrap().clone(); - info!( - "Found eligible slot: {:?}. Target start: {}, Target end: {}", - forester_slot.slot, - forester_slot.start_solana_slot, - forester_slot.end_solana_slot - ); - - let context_str = format!( - "process_queue (wait_until_slot_reached), tree: {}", - tree.tree_accounts.merkle_tree - ); - debug!(context = %context_str, "Attempting to get RPC connection for wait..."); - - let rpc_result = self.rpc_pool.get_connection().await; - match rpc_result { + .find_map(|(idx, opt_slot)| opt_slot.as_ref().map(|s| (idx, s.clone()))); + + if let Some((slot_idx, light_slot_details)) = next_slot_to_process { + match self + .process_light_slot( + epoch_info, + epoch_pda, + &tree_schedule.tree_accounts, + &light_slot_details, + ) + .await + { Ok(_) => { - debug!(context = %context_str, "Successfully got RPC connection for wait."); + trace!( + "Successfully processed light slot {:?}", + light_slot_details.slot + ); } - Err(ref e) => { - error!(context = %context_str, "Failed to get RPC connection for wait: {:?}", e); + Err(e) => { + error!( + "Error processing light slot {:?}: {:?}. Skipping this slot.", + light_slot_details.slot, e + ); } } - let mut rpc = rpc_result?; + tree_schedule.slots[slot_idx] = None; // Mark as attempted/processed + } else { info!( - "Current estimated solana slot: {}, waiting for slot {} to begin", - self.slot_tracker.estimated_current_slot(), - forester_slot.start_solana_slot + "No further eligible slots in schedule for tree {}", + tree_schedule.tree_accounts.merkle_tree ); + break 'outer_slot_loop; + } - if let Err(e) = wait_until_slot_reached( - &mut *rpc, - &self.slot_tracker, - forester_slot.start_solana_slot, - ) - .await - { - error!( - "Error waiting for slot {} to start: {:?}. Skipping slot.", - forester_slot.start_solana_slot, e - ); - tree.slots[slot_index] = None; - continue 'outer; - } - info!( - "Reached start slot {}. Beginning processing window until slot {}.", - forester_slot.start_solana_slot, forester_slot.end_solana_slot - ); - 'inner: loop { - estimated_slot = self.slot_tracker.estimated_current_slot(); - if estimated_slot >= forester_slot.end_solana_slot { - info!( - "Ending processing for slot {:?} ({}) due to reaching/exceeding end slot {}", - forester_slot.slot, forester_slot.start_solana_slot, forester_slot.end_solana_slot - ); - break 'inner; - } + tokio::task::yield_now().await; + current_slot = self.slot_tracker.estimated_current_slot(); + } - debug!( - "Inner loop iteration for slot {:?}. Current estimated: {}, End: {}", - forester_slot.slot, estimated_slot, forester_slot.end_solana_slot - ); + info!( + "Exiting process_queue for tree {}", + tree_schedule.tree_accounts.merkle_tree + ); + Ok(()) + } - let current_light_slot = (estimated_slot - epoch_info.phases.active.start) - / epoch_pda.protocol_config.slot_length; - if current_light_slot != forester_slot.slot { - warn!( - "Current light slot {} differs from processing slot {}. Exiting slot processing.", - current_light_slot, forester_slot.slot - ); - break 'inner; - } - let eligible_forester_slot_index = - match ForesterEpochPda::get_eligible_forester_index( - current_light_slot, - &tree.tree_accounts.queue, - epoch_pda.total_epoch_weight.unwrap(), - epoch_info.epoch, - ) { - Ok(idx) => idx, - Err(e) => { - error!("Failed to calculate eligible forester index: {:?}", e); - break 'inner; - } - }; + #[instrument( + level = "debug", + skip(self, epoch_info, epoch_pda, tree_accounts, forester_slot_details), + fields(forester = %self.config.payer_keypair.pubkey(), epoch = epoch_info.epoch, + tree = %tree_accounts.merkle_tree) + )] + async fn process_light_slot( + &self, + epoch_info: &Epoch, + epoch_pda: &ForesterEpochPda, + tree_accounts: &TreeAccounts, + forester_slot_details: &ForesterSlot, + ) -> Result<()> { + trace!( + "Found eligible slot: {:?}. Target start: {}, Target end: {}", + forester_slot_details.slot, + forester_slot_details.start_solana_slot, + forester_slot_details.end_solana_slot + ); + let mut rpc = self.rpc_pool.get_connection().await?; + wait_until_slot_reached( + &mut *rpc, + &self.slot_tracker, + forester_slot_details.start_solana_slot, + ) + .await?; - if !epoch_pda.is_eligible(eligible_forester_slot_index) { - warn!( - "Forester {} is no longer eligible to process tree {} in light slot {}. Exiting slot processing.", - self.config.payer_keypair.pubkey(), - tree.tree_accounts.merkle_tree, - current_light_slot - ); - break 'inner; - } + let mut estimated_slot = self.slot_tracker.estimated_current_slot(); - let mut items_processed_this_iteration = 0; - let mut iteration_failed = false; - let processing_start_time = Instant::now(); + 'inner_processing_loop: loop { + if estimated_slot >= forester_slot_details.end_solana_slot { + trace!( + "Ending processing for slot {:?} due to time limit.", + forester_slot_details.slot + ); + break 'inner_processing_loop; + } - if tree.tree_accounts.tree_type == TreeType::StateV1 - || tree.tree_accounts.tree_type == TreeType::AddressV1 - { - let transaction_timeout_buffer = Duration::ZERO; + let current_light_slot = (estimated_slot - epoch_info.phases.active.start) + / epoch_pda.protocol_config.slot_length; + if current_light_slot != forester_slot_details.slot { + warn!("Light slot mismatch. Exiting processing for this slot."); + break 'inner_processing_loop; + } - let remaining_time_timeout = calculate_remaining_time_or_default( - estimated_slot, - forester_slot.end_solana_slot, - transaction_timeout_buffer, - ); + if !self + .check_forester_eligibility( + epoch_pda, + current_light_slot, + &tree_accounts.queue, + epoch_info.epoch, + ) + .await? + { + break 'inner_processing_loop; + } - trace!( - "Calculated remaining time timeout for send_batched_transactions: {:?}", - remaining_time_timeout - ); + let processing_start_time = Instant::now(); + let items_processed_this_iteration = match self + .dispatch_tree_processing( + epoch_info, + epoch_pda, + tree_accounts, + forester_slot_details, + estimated_slot, + ) + .await + { + Ok(count) => count, + Err(e) => { + error!( + "Failed processing in slot {:?}: {:?}", + forester_slot_details.slot, e + ); + break 'inner_processing_loop; + } + }; - let batched_tx_config = SendBatchedTransactionsConfig { - num_batches: 1, - build_transaction_batch_config: BuildTransactionBatchConfig { - batch_size: 50, - compute_unit_price: Some(10_000), - compute_unit_limit: Some(300_000), - enable_priority_fees: self - .config - .transaction_config - .enable_priority_fees, - }, - queue_config: self.config.queue_config, - retry_config: RetryConfig { - timeout: remaining_time_timeout, - ..self.config.retry_config - }, - light_slot_length: epoch_pda.protocol_config.slot_length, - }; + self.update_metrics_and_counts( + epoch_info.epoch, + items_processed_this_iteration, + processing_start_time.elapsed(), + ) + .await; - let transaction_builder = EpochManagerTransactions::new( - self.indexer.clone(), - self.rpc_pool.clone(), - epoch_info.epoch, - self.tx_cache.clone(), - ); + push_metrics(&self.config.external_services.pushgateway_url).await?; + estimated_slot = self.slot_tracker.estimated_current_slot(); + } + Ok(()) + } - info!( - "Attempting to send transactions within slot {:?}", - forester_slot.slot - ); - match send_batched_transactions( - &self.config.payer_keypair, - &self.config.derivation_pubkey, - self.rpc_pool.clone(), - &batched_tx_config, - tree.tree_accounts, - &transaction_builder, - ) - .await - { - Ok(num_sent) => { - if num_sent > 0 { - trace!("{} transactions sent in this iteration", num_sent); - let iteration_duration = processing_start_time.elapsed(); - queue_metric_update( - epoch_info.epoch, - num_sent, - iteration_duration, - ) - .await; - self.increment_processed_items_count( - epoch_info.epoch, - num_sent, - ) - .await; - items_processed_this_iteration = num_sent; - } else { - info!("send_batched_transactions processed 0 items. Queue likely empty for this attempt."); - } - } - Err(e) => { - error!( - "Failed to send transactions within slot {:?}: {:?}", - forester_slot.slot, e - ); - iteration_failed = true; - } - } + async fn check_forester_eligibility( + &self, + epoch_pda: &ForesterEpochPda, + current_light_slot: u64, + queue_pubkey: &Pubkey, + current_epoch_num: u64, + ) -> Result { + let total_epoch_weight = epoch_pda.total_epoch_weight.ok_or_else(|| { + anyhow::anyhow!( + "Total epoch weight not available in ForesterEpochPda for epoch {}", + current_epoch_num + ) + })?; - if let Err(e) = self.rollover_if_needed(&tree.tree_accounts).await { - error!("Rollover check failed during slot processing: {:?}", e); - } - } else if tree.tree_accounts.tree_type == TreeType::StateV2 - || tree.tree_accounts.tree_type == TreeType::AddressV2 - { - let batch_context = BatchContext { - rpc_pool: self.rpc_pool.clone(), - indexer: self.indexer.clone(), - authority: self.config.payer_keypair.insecure_clone(), - derivation: self.config.derivation_pubkey, - epoch: epoch_info.epoch, - merkle_tree: tree.tree_accounts.merkle_tree, - output_queue: tree.tree_accounts.queue, - ixs_per_tx: self.config.transaction_config.batch_ixs_per_tx, - }; - match process_batched_operations( - batch_context, - tree.tree_accounts.tree_type, - ) - .await - { - Ok(processed_count) => { - if processed_count > 0 { - info!( - "Processed {} V2 operations for tree type {:?}", - processed_count, tree.tree_accounts.tree_type - ); - let iteration_duration = processing_start_time.elapsed(); - queue_metric_update( - epoch_info.epoch, - processed_count, - iteration_duration, - ) - .await; - self.increment_processed_items_count( - epoch_info.epoch, - processed_count, - ) - .await; - items_processed_this_iteration = processed_count; - - trace!("Checking for V2 rollover readiness after processing batch..."); - if let Err(e) = - self.rollover_if_needed(&tree.tree_accounts).await - { - error!( - "V2 Rollover check failed during slot processing: {:?}", - e - ); - } else { - trace!("V2 Rollover check completed."); - } - } else { - info!("process_batched_operations processed 0 items. Queue likely empty for this attempt."); - } - } - Err(e) => { - error!( - "Failed to process V2 batched operations for tree {:?} within slot {:?}: {:?}", - tree.tree_accounts.merkle_tree, forester_slot.slot, e - ); - iteration_failed = true; - } - } - } else { - warn!( - "Unsupported tree type encountered in process_queue: {:?}", - tree.tree_accounts.tree_type - ); - iteration_failed = true; - } + let eligible_forester_slot_index = ForesterEpochPda::get_eligible_forester_index( + current_light_slot, + queue_pubkey, + total_epoch_weight, + current_epoch_num, + ) + .map_err(|e| { + error!("Failed to calculate eligible forester index: {:?}", e); + anyhow::anyhow!("Eligibility calculation failed: {}", e) + })?; - if iteration_failed { - error!( - "Exiting inner loop for slot {:?} due to processing error.", - forester_slot.slot - ); - break 'inner; - } + if !epoch_pda.is_eligible(eligible_forester_slot_index) { + warn!( + "Forester {} is no longer eligible to process tree {} in light slot {}.", + self.config.payer_keypair.pubkey(), + queue_pubkey, + current_light_slot + ); + return Ok(false); + } + Ok(true) + } - push_metrics(&self.config.external_services.pushgateway_url).await?; + async fn dispatch_tree_processing( + &self, + epoch_info: &Epoch, + epoch_pda: &ForesterEpochPda, + tree_accounts: &TreeAccounts, + forester_slot_details: &ForesterSlot, + current_solana_slot: u64, + ) -> Result { + match tree_accounts.tree_type { + TreeType::StateV1 | TreeType::AddressV1 => { + self.process_v1( + epoch_info, + epoch_pda, + tree_accounts, + forester_slot_details, + current_solana_slot, + ) + .await + } + TreeType::StateV2 | TreeType::AddressV2 => { + self.process_v2(epoch_info, tree_accounts).await + } + } + } - if items_processed_this_iteration == 0 { - let queue_check_interval = Duration::from_secs(2); - debug!("No items processed, sleeping for {:?} before re-checking queue/time within slot.", queue_check_interval); - sleep(queue_check_interval).await; - } else { - trace!("Yielding after processing items within slot."); - tokio::task::yield_now().await; - } + async fn process_v1( + &self, + epoch_info: &Epoch, + epoch_pda: &ForesterEpochPda, + tree_accounts: &TreeAccounts, + forester_slot_details: &ForesterSlot, + current_solana_slot: u64, + ) -> Result { + let transaction_timeout_buffer = Duration::from_secs(2); + let remaining_time_timeout = calculate_remaining_time_or_default( + current_solana_slot, + forester_slot_details.end_solana_slot, + transaction_timeout_buffer, + ); - if self.slot_tracker.estimated_current_slot() >= forester_slot.end_solana_slot { - info!( - "Exiting inner loop for slot {:?} after sleep/yield time check.", - forester_slot.slot - ); - break 'inner; - } - } + let batched_tx_config = SendBatchedTransactionsConfig { + num_batches: 1, + build_transaction_batch_config: BuildTransactionBatchConfig { + batch_size: self.config.transaction_config.legacy_ixs_per_tx as u64, + compute_unit_price: Some(10_000), // is dynamic, sets max + compute_unit_limit: Some(self.config.transaction_config.cu_limit), + enable_priority_fees: self.config.transaction_config.enable_priority_fees, + max_concurrent_sends: Some(50), + }, + queue_config: self.config.queue_config, + retry_config: RetryConfig { + timeout: remaining_time_timeout, + ..self.config.retry_config + }, + light_slot_length: epoch_pda.protocol_config.slot_length, + }; - info!( - "Finished processing window for slot {:?} (Started: {}, Ended: {}). Marking as processed.", - forester_slot.slot, forester_slot.start_solana_slot, forester_slot.end_solana_slot - ); - tree.slots[slot_index] = None; - } else { - info!("No further eligible slots found in schedule for this epoch and tree."); - break 'outer; + let transaction_builder = EpochManagerTransactions::new( + self.indexer.clone(), + self.rpc_pool.clone(), + epoch_info.epoch, + self.tx_cache.clone(), + ); + + let num_sent = send_batched_transactions( + &self.config.payer_keypair, + &self.config.derivation_pubkey, + self.rpc_pool.clone(), + &batched_tx_config, + *tree_accounts, + &transaction_builder, + ) + .await?; + + match self.rollover_if_needed(tree_accounts).await { + Ok(_) => Ok(num_sent), + Err(e) => { + error!("Failed to rollover tree: {:?}", e); + Err(e) } - tokio::task::yield_now().await; - estimated_slot = self.slot_tracker.estimated_current_slot(); } + } - info!( - "Exiting process_queue for epoch {}, tree {}", - epoch_info.epoch, tree.tree_accounts.merkle_tree - ); + async fn process_v2(&self, epoch_info: &Epoch, tree_accounts: &TreeAccounts) -> Result { + let batch_context = BatchContext { + rpc_pool: self.rpc_pool.clone(), + indexer: self.indexer.clone(), + authority: self.config.payer_keypair.insecure_clone(), + derivation: self.config.derivation_pubkey, + epoch: epoch_info.epoch, + merkle_tree: tree_accounts.merkle_tree, + output_queue: tree_accounts.queue, + ixs_per_tx: self.config.transaction_config.batch_ixs_per_tx, + }; - Ok(()) + process_batched_operations(batch_context, tree_accounts.tree_type) + .await + .map_err(|e| anyhow!("Failed to process V2 operations: {}", e)) + } + + async fn update_metrics_and_counts( + &self, + epoch_num: u64, + items_processed: usize, + duration: Duration, + ) { + if items_processed > 0 { + trace!( + "{} items processed in this iteration, duration: {:?}", + items_processed, + duration + ); + queue_metric_update(epoch_num, items_processed, duration).await; + self.increment_processed_items_count(epoch_num, items_processed) + .await; + } } async fn rollover_if_needed(&self, tree_account: &TreeAccounts) -> Result<()> { @@ -1220,7 +1197,7 @@ impl + IndexerType> EpochManager { .await { Ok(_) => { - info!("Work reported successfully"); + info!("Work reported"); } Err(e) => { if let RpcError::ClientError(client_error) = &e { @@ -1255,7 +1232,6 @@ impl + IndexerType> EpochManager { error: e.to_string(), })?; - info!("Work reported"); Ok(()) } @@ -1349,7 +1325,7 @@ pub async fn run_service + IndexerType>( let rpc = rpc_pool.get_connection().await?; fetch_trees(&*rpc).await? }; - info!("Fetched initial trees: {:?}", trees); + trace!("Fetched initial trees: {:?}", trees); let (new_tree_sender, _) = broadcast::channel(100); diff --git a/forester/src/errors.rs b/forester/src/errors.rs index dd5087ee92..86e5e196c8 100644 --- a/forester/src/errors.rs +++ b/forester/src/errors.rs @@ -8,7 +8,7 @@ use solana_program::{program_error::ProgramError, pubkey::Pubkey}; use thiserror::Error; use tracing::{info, warn}; -use crate::batch_processor::BatchProcessError; +use crate::processor::v2::BatchProcessError; #[derive(Error, Debug)] pub enum ForesterError { @@ -36,8 +36,8 @@ pub enum ForesterError { #[error("RPC error: {0}")] Rpc(#[from] RpcError), - #[error("Pool error: {0}")] - Pool(#[from] PoolError), + #[error("RPC pool error: {0}")] + RpcPool(#[from] PoolError), #[error("Program error: {0}")] Program(#[from] ProgramError), diff --git a/forester/src/lib.rs b/forester/src/lib.rs index f94e21e6bd..45aebdc22f 100644 --- a/forester/src/lib.rs +++ b/forester/src/lib.rs @@ -1,6 +1,5 @@ pub type Result = anyhow::Result; -mod batch_processor; pub mod cli; pub mod config; pub mod epoch_manager; @@ -10,10 +9,10 @@ pub mod helius_priority_fee_types; mod indexer_type; pub mod metrics; pub mod pagerduty; +pub mod processor; pub mod pubsub_client; pub mod queue_helpers; pub mod rollover; -pub mod send_transaction; mod slot_tracker; pub mod smart_transaction; pub mod telemetry; @@ -33,7 +32,6 @@ use light_client::{ rpc_pool::SolanaRpcPool, }; use light_compressed_account::TreeType; -use send_transaction::ProcessedHashCache; use solana_sdk::commitment_config::CommitmentConfig; use tokio::sync::{mpsc, oneshot, Mutex}; use tracing::debug; @@ -42,6 +40,7 @@ use crate::{ epoch_manager::{run_service, WorkReport}, indexer_type::IndexerType, metrics::QUEUE_LENGTH, + processor::tx_cache::ProcessedHashCache, queue_helpers::fetch_queue_item_data, slot_tracker::SlotTracker, utils::get_protocol_config, diff --git a/forester/src/processor/mod.rs b/forester/src/processor/mod.rs new file mode 100644 index 0000000000..b6382a86bb --- /dev/null +++ b/forester/src/processor/mod.rs @@ -0,0 +1,3 @@ +pub mod tx_cache; +pub mod v1; +pub mod v2; diff --git a/forester/src/processor/tx_cache.rs b/forester/src/processor/tx_cache.rs new file mode 100644 index 0000000000..f274552646 --- /dev/null +++ b/forester/src/processor/tx_cache.rs @@ -0,0 +1,33 @@ +use std::{collections::HashMap, time::Duration}; + +use tokio::time::Instant; + +#[derive(Debug, Clone)] +pub struct ProcessedHashCache { + entries: HashMap, + ttl: Duration, +} + +impl ProcessedHashCache { + pub fn new(ttl_seconds: u64) -> Self { + Self { + entries: HashMap::new(), + ttl: Duration::from_secs(ttl_seconds), + } + } + + pub fn add(&mut self, hash: &str) { + self.entries.insert(hash.to_string(), Instant::now()); + } + + pub fn contains(&mut self, hash: &str) -> bool { + self.cleanup(); + self.entries.contains_key(hash) + } + + pub fn cleanup(&mut self) { + let now = Instant::now(); + self.entries + .retain(|_, timestamp| now.duration_since(*timestamp) < self.ttl); + } +} diff --git a/forester/src/processor/v1/config.rs b/forester/src/processor/v1/config.rs new file mode 100644 index 0000000000..87fe036738 --- /dev/null +++ b/forester/src/processor/v1/config.rs @@ -0,0 +1,29 @@ +use light_client::rpc::RetryConfig; + +use crate::config::QueueConfig; + +#[derive(Debug, Clone, Copy)] +pub struct CapConfig { + pub rec_fee_microlamports_per_cu: u64, + pub min_fee_lamports: u64, + pub max_fee_lamports: u64, + pub compute_unit_limit: u64, +} + +#[derive(Debug, Clone, Copy)] +pub struct SendBatchedTransactionsConfig { + pub num_batches: u64, + pub build_transaction_batch_config: BuildTransactionBatchConfig, + pub queue_config: QueueConfig, + pub retry_config: RetryConfig, + pub light_slot_length: u64, +} + +#[derive(Debug, Clone, Copy)] +pub struct BuildTransactionBatchConfig { + pub batch_size: u64, + pub compute_unit_price: Option, + pub compute_unit_limit: Option, + pub enable_priority_fees: bool, + pub max_concurrent_sends: Option, +} diff --git a/forester/src/processor/v1/helpers.rs b/forester/src/processor/v1/helpers.rs new file mode 100644 index 0000000000..401d3c27aa --- /dev/null +++ b/forester/src/processor/v1/helpers.rs @@ -0,0 +1,259 @@ +use std::sync::Arc; + +use account_compression::{ + processor::initialize_address_merkle_tree::Pubkey, + utils::constants::{ + ADDRESS_MERKLE_TREE_CHANGELOG, ADDRESS_MERKLE_TREE_INDEXED_CHANGELOG, + STATE_MERKLE_TREE_CHANGELOG, + }, +}; +use forester_utils::utils::wait_for_indexer; +use light_client::{indexer::Indexer, rpc::RpcConnection, rpc_pool::SolanaRpcPool}; +use light_compressed_account::TreeType; +use light_registry::account_compression_cpi::sdk::{ + create_nullify_instruction, create_update_address_merkle_tree_instruction, + CreateNullifyInstructionInputs, UpdateAddressMerkleTreeInstructionInputs, +}; +use reqwest::Url; +use solana_program::instruction::Instruction; +use tokio::{join, sync::Mutex}; +use tracing::warn; + +use crate::{ + epoch_manager::{MerkleProofType, WorkItem}, + errors::ForesterError, + helius_priority_fee_types::{ + GetPriorityFeeEstimateOptions, GetPriorityFeeEstimateRequest, + GetPriorityFeeEstimateResponse, RpcRequest, RpcResponse, + }, + processor::v1::config::CapConfig, +}; + +/// Work items should be of only one type and tree +pub async fn fetch_proofs_and_create_instructions>( + authority: Pubkey, + derivation: Pubkey, + pool: Arc>, + indexer: Arc>, + epoch: u64, + work_items: &[WorkItem], +) -> crate::Result<(Vec, Vec)> { + let mut proofs = Vec::new(); + let mut instructions = vec![]; + + let (address_items, state_items): (Vec<_>, Vec<_>) = work_items + .iter() + .partition(|item| matches!(item.tree_account.tree_type, TreeType::AddressV1)); + + for item in state_items.iter() { + if item.tree_account.tree_type != TreeType::StateV1 { + warn!( + "State item has unexpected tree type: {:?}", + item.tree_account.tree_type + ); + } + } + let state_items = state_items + .into_iter() + .filter(|item| item.tree_account.tree_type == TreeType::StateV1) + .collect::>(); + + let address_data = if !address_items.is_empty() { + let merkle_tree = address_items + .first() + .ok_or_else(|| ForesterError::General { + error: "No address items found".to_string(), + })? + .tree_account + .merkle_tree + .to_bytes(); + let addresses: Vec<[u8; 32]> = address_items + .iter() + .map(|item| item.queue_item_data.hash) + .collect(); + Some((merkle_tree, addresses)) + } else { + None + }; + + let state_data = if !state_items.is_empty() { + let states: Vec = state_items + .iter() + .map(|item| bs58::encode(&item.queue_item_data.hash).into_string()) + .collect(); + Some(states) + } else { + None + }; + + let indexer_guard = indexer.lock().await; + let mut rpc = pool.get_connection().await?; + + if let Err(e) = wait_for_indexer(&mut *rpc, &*indexer_guard).await { + warn!("Indexer not fully caught up, but proceeding anyway: {}", e); + } + + let (address_proofs_result, state_proofs_result) = { + let address_future = async { + if let Some((merkle_tree, addresses)) = address_data { + indexer_guard + .get_multiple_new_address_proofs(merkle_tree, addresses) + .await + } else { + Ok(vec![]) + } + }; + + let state_future = async { + if let Some(states) = state_data { + indexer_guard + .get_multiple_compressed_account_proofs(states) + .await + } else { + Ok(vec![]) + } + }; + + join!(address_future, state_future) + }; + + let address_proofs = match address_proofs_result { + Ok(proofs) => proofs, + Err(e) => { + return Err(anyhow::anyhow!("Failed to get address proofs: {}", e)); + } + }; + + let state_proofs = match state_proofs_result { + Ok(proofs) => proofs, + Err(e) => { + return Err(anyhow::anyhow!("Failed to get state proofs: {}", e)); + } + }; + + for (item, proof) in address_items.iter().zip(address_proofs.into_iter()) { + proofs.push(MerkleProofType::AddressProof(proof.clone())); + let instruction = create_update_address_merkle_tree_instruction( + UpdateAddressMerkleTreeInstructionInputs { + authority, + derivation, + address_merkle_tree: item.tree_account.merkle_tree, + address_queue: item.tree_account.queue, + value: item.queue_item_data.index as u16, + low_address_index: proof.low_address_index, + low_address_value: proof.low_address_value, + low_address_next_index: proof.low_address_next_index, + low_address_next_value: proof.low_address_next_value, + low_address_proof: proof.low_address_proof, + changelog_index: (proof.root_seq % ADDRESS_MERKLE_TREE_CHANGELOG) as u16, + indexed_changelog_index: (proof.root_seq % ADDRESS_MERKLE_TREE_INDEXED_CHANGELOG) + as u16, + is_metadata_forester: false, + }, + epoch, + ); + instructions.push(instruction); + } + + // Process state proofs and create instructions + for (item, proof) in state_items.iter().zip(state_proofs.into_iter()) { + proofs.push(MerkleProofType::StateProof(proof.clone())); + let instruction = create_nullify_instruction( + CreateNullifyInstructionInputs { + nullifier_queue: item.tree_account.queue, + merkle_tree: item.tree_account.merkle_tree, + change_log_indices: vec![proof.root_seq % STATE_MERKLE_TREE_CHANGELOG], + leaves_queue_indices: vec![item.queue_item_data.index as u16], + indices: vec![proof.leaf_index], + proofs: vec![proof.proof.clone()], + authority, + derivation, + is_metadata_forester: false, + }, + epoch, + ); + instructions.push(instruction); + } + + Ok((proofs, instructions)) +} + +/// Request priority fee estimate from Helius RPC endpoint +pub async fn request_priority_fee_estimate( + url: &Url, + account_keys: Vec, +) -> crate::Result { + if url.host_str() != Some("mainnet") { + return Ok(10_000); + } + + let priority_fee_request = GetPriorityFeeEstimateRequest { + transaction: None, + account_keys: Some( + account_keys + .iter() + .map(|pubkey| bs58::encode(pubkey).into_string()) + .collect(), + ), + options: Some(GetPriorityFeeEstimateOptions { + include_all_priority_fee_levels: None, + recommended: Some(true), + include_vote: None, + lookback_slots: None, + priority_level: None, + transaction_encoding: None, + }), + }; + + let rpc_request = RpcRequest::new( + "getPriorityFeeEstimate".to_string(), + serde_json::json!({ + "get_priority_fee_estimate_request": priority_fee_request + }), + ); + + let client = reqwest::Client::new(); + let response = client + .post(url.clone()) + .header("Content-Type", "application/json") + .json(&rpc_request) + .send() + .await?; + + let response_text = response.text().await?; + + let response: RpcResponse = + serde_json::from_str(&response_text)?; + + response + .result + .priority_fee_estimate + .map(|estimate| estimate as u64) + .ok_or( + ForesterError::General { + error: "Priority fee estimate not available".to_string(), + } + .into(), + ) +} + +/// Calculate the compute unit price in microLamports based on the target lamports and compute units +#[allow(dead_code)] +pub fn calculate_compute_unit_price(target_lamports: u64, compute_units: u64) -> u64 { + ((target_lamports * 1_000_000) as f64 / compute_units as f64).ceil() as u64 +} + +/// Get a capped priority fee for transaction between min and max. +#[allow(dead_code)] +pub fn get_capped_priority_fee(cap_config: CapConfig) -> u64 { + if cap_config.max_fee_lamports < cap_config.min_fee_lamports { + panic!("Max fee is less than min fee"); + } + + let priority_fee_max = + calculate_compute_unit_price(cap_config.max_fee_lamports, cap_config.compute_unit_limit); + let priority_fee_min = + calculate_compute_unit_price(cap_config.min_fee_lamports, cap_config.compute_unit_limit); + let capped_fee = std::cmp::min(cap_config.rec_fee_microlamports_per_cu, priority_fee_max); + std::cmp::max(capped_fee, priority_fee_min) +} diff --git a/forester/src/processor/v1/mod.rs b/forester/src/processor/v1/mod.rs new file mode 100644 index 0000000000..b0b7ed7086 --- /dev/null +++ b/forester/src/processor/v1/mod.rs @@ -0,0 +1,4 @@ +pub mod config; +pub mod helpers; +pub mod send_transaction; +pub mod tx_builder; diff --git a/forester/src/processor/v1/send_transaction.rs b/forester/src/processor/v1/send_transaction.rs new file mode 100644 index 0000000000..5ec9f32495 --- /dev/null +++ b/forester/src/processor/v1/send_transaction.rs @@ -0,0 +1,373 @@ +use std::{ + sync::{ + atomic::{AtomicBool, AtomicUsize, Ordering}, + Arc, + }, + vec, +}; + +use account_compression::utils::constants::{ADDRESS_QUEUE_VALUES, STATE_NULLIFIER_QUEUE_VALUES}; +use forester_utils::forester_epoch::TreeAccounts; +use futures::StreamExt; +use light_client::{rpc::RpcConnection, rpc_pool::SolanaRpcPool}; +use light_compressed_account::TreeType; +use light_registry::utils::get_forester_epoch_pda_from_authority; +use reqwest::Url; +use solana_client::rpc_config::RpcSendTransactionConfig; +use solana_sdk::{ + commitment_config::CommitmentLevel, + hash::Hash, + pubkey::Pubkey, + signature::{Keypair, Signature, Signer}, + transaction::Transaction, +}; +use tokio::time::Instant; +use tracing::{debug, error, info, trace, warn}; + +use crate::{ + epoch_manager::WorkItem, + errors::ForesterError, + processor::v1::{ + config::SendBatchedTransactionsConfig, helpers::request_priority_fee_estimate, + tx_builder::TransactionBuilder, + }, + queue_helpers::fetch_queue_item_data, + Result, +}; + +struct PreparedBatchData { + work_items: Vec, + recent_blockhash: Hash, + last_valid_block_height: u64, + priority_fee: u64, + timeout_deadline: Instant, +} + +enum TransactionSendResult { + Success(Signature), + Failure(ForesterError, Option), + Cancelled, + Timeout, +} + +/// Setting: +/// 1. We have 1 light slot (n solana slots), and elements in queue +/// 2. we want to send as many elements from the queue as possible +pub async fn send_batched_transactions( + payer: &Keypair, + derivation: &Pubkey, + pool: Arc>, + config: &SendBatchedTransactionsConfig, + tree_accounts: TreeAccounts, + transaction_builder: &T, +) -> Result { + let function_start_time = Instant::now(); + + let num_sent_transactions = Arc::new(AtomicUsize::new(0)); + let operation_cancel_signal = Arc::new(AtomicBool::new(false)); + + let data = match prepare_batch_prerequisites( + &payer.pubkey(), + derivation, + &pool, + config, + tree_accounts, + transaction_builder, + function_start_time, + ) + .await? + { + Some(data) => data, + None => { + trace!(tree.id = %tree_accounts.merkle_tree, queue.id = %tree_accounts.queue, "Preparation returned no data, 0 transactions sent."); + return Ok(0); + } + }; + + let max_concurrent_sends = config + .build_transaction_batch_config + .max_concurrent_sends + .unwrap_or(1) + .max(1); + + info!(tree = %tree_accounts.merkle_tree, "Starting transaction sending loop. Timeout: {:?}. Max concurrent sends: {}", config.retry_config.timeout, max_concurrent_sends); + + for work_chunk in data + .work_items + .chunks(config.build_transaction_batch_config.batch_size as usize) + { + if operation_cancel_signal.load(Ordering::SeqCst) { + trace!(tree = %tree_accounts.merkle_tree, "Global cancellation signal received, stopping batch processing."); + break; + } + if Instant::now() >= data.timeout_deadline { + warn!(tree = %tree_accounts.merkle_tree, "Reached global timeout deadline before processing next chunk, stopping."); + break; + } + + debug!(tree = %tree_accounts.merkle_tree, "Processing chunk of size {}", work_chunk.len()); + let build_start_time = Instant::now(); + + let (transactions_to_send, _) = match transaction_builder + .build_signed_transaction_batch( + payer, + derivation, + &data.recent_blockhash, + data.last_valid_block_height, + data.priority_fee, + work_chunk, + config.build_transaction_batch_config, + ) + .await + { + Ok(res) => res, + Err(e) => { + error!(tree = %tree_accounts.merkle_tree, "Failed to build transaction batch: {:?}", e); + operation_cancel_signal.store(true, Ordering::SeqCst); + break; + } + }; + debug!(tree = %tree_accounts.merkle_tree, "Built {} transactions in {:?}", transactions_to_send.len(), build_start_time.elapsed()); + + if Instant::now() >= data.timeout_deadline { + warn!(tree = %tree_accounts.merkle_tree, "Reached global timeout deadline after building transactions, stopping."); + break; + } + + if transactions_to_send.is_empty() { + trace!(tree = %tree_accounts.merkle_tree, "Built batch resulted in 0 transactions, skipping send for this chunk."); + continue; + } + + execute_transaction_chunk_sending( + transactions_to_send, + Arc::clone(&pool), + max_concurrent_sends, + data.timeout_deadline, + Arc::clone(&operation_cancel_signal), + Arc::clone(&num_sent_transactions), + ) + .await; + } + + let total_sent_successfully = num_sent_transactions.load(Ordering::SeqCst); + debug!(tree = %tree_accounts.merkle_tree, "Transaction sending loop finished. Total transactions sent successfully: {}", total_sent_successfully); + Ok(total_sent_successfully) +} + +async fn prepare_batch_prerequisites( + payer_pubkey: &Pubkey, + derivation: &Pubkey, + pool: &Arc>, + config: &SendBatchedTransactionsConfig, + tree_accounts: TreeAccounts, + transaction_builder: &T, + start_time: Instant, +) -> Result> { + let tree_id_str = tree_accounts.merkle_tree.to_string(); + + let (queue_total_capacity, queue_fetch_start_index, queue_fetch_length) = + match tree_accounts.tree_type { + TreeType::StateV1 => ( + STATE_NULLIFIER_QUEUE_VALUES, + config.queue_config.state_queue_start_index, + config.queue_config.state_queue_length, + ), + TreeType::AddressV1 => ( + ADDRESS_QUEUE_VALUES, + config.queue_config.address_queue_start_index, + config.queue_config.address_queue_length, + ), + _ => { + error!( + tree = %tree_id_str, + "prepare_batch_prerequisites called with unsupported tree type: {:?}", + tree_accounts.tree_type + ); + return Err(ForesterError::InvalidTreeType(tree_accounts.tree_type).into()); + } + }; + + let queue_item_data = { + let mut rpc = pool.get_connection().await.map_err(|e| { + error!(tree = %tree_id_str, "Failed to get RPC for queue data: {:?}", e); + ForesterError::RpcPool(e) + })?; + fetch_queue_item_data( + &mut *rpc, + &tree_accounts.queue, + queue_fetch_start_index, + queue_fetch_length, + queue_total_capacity, + ) + .await + .map_err(|e| { + error!(tree = %tree_id_str, "Failed to fetch queue item data: {:?}", e); + ForesterError::General { + error: format!("Fetch queue data failed for {}: {}", tree_id_str, e), + } + })? + }; + + if queue_item_data.is_empty() { + trace!(tree = %tree_id_str, "Queue is empty, no transactions to send."); + return Ok(None); // Return None to indicate no work + } + + let (recent_blockhash, last_valid_block_height) = { + let mut rpc = pool.get_connection().await.map_err(|e| { + error!(tree = %tree_id_str, "Failed to get RPC for blockhash: {:?}", e); + ForesterError::RpcPool(e) + })?; + let r_blockhash = rpc.get_latest_blockhash().await.map_err(|e| { + error!(tree = %tree_id_str, "Failed to get latest blockhash: {:?}", e); + ForesterError::Rpc(e) + })?; + (r_blockhash.0, r_blockhash.1 + 150) + }; + + let priority_fee = if config.build_transaction_batch_config.enable_priority_fees { + let rpc_for_fee = pool.get_connection().await.map_err(|e| { + error!(tree = %tree_id_str, "Failed to get RPC for priority fee: {:?}", e); + ForesterError::RpcPool(e) + })?; + let forester_epoch_pda_pubkey = + get_forester_epoch_pda_from_authority(derivation, transaction_builder.epoch()).0; + let account_keys = vec![ + *payer_pubkey, + forester_epoch_pda_pubkey, + tree_accounts.queue, + tree_accounts.merkle_tree, + ]; + let rpc_url_str = rpc_for_fee.get_url(); + let url = Url::parse(&rpc_url_str).map_err(|e| { + error!(tree = %tree_id_str, "Failed to parse RPC URL for priority fee: {}, error: {:?}", rpc_url_str, e); + ForesterError::General { error: format!("Invalid RPC URL: {}", rpc_url_str) } + })?; + request_priority_fee_estimate(&url, account_keys).await? + } else { + 10_000 + }; + + let work_items: Vec = queue_item_data + .into_iter() + .map(|data| WorkItem { + tree_account: tree_accounts, + queue_item_data: data, + }) + .collect(); + + let timeout_deadline = start_time + config.retry_config.timeout; + + Ok(Some(PreparedBatchData { + work_items, + recent_blockhash, + last_valid_block_height, + priority_fee, + timeout_deadline, + })) +} + +async fn execute_transaction_chunk_sending( + transactions: Vec, + pool: Arc>, + max_concurrent_sends: usize, + timeout_deadline: Instant, + cancel_signal: Arc, + num_sent_transactions: Arc, +) { + if transactions.is_empty() { + trace!("No transactions in this chunk to send."); + return; + } + + let transaction_send_futures = transactions.into_iter().map(|tx| { + let pool_clone = Arc::clone(&pool); + let rpc_send_config = RpcSendTransactionConfig { + skip_preflight: true, + max_retries: Some(0), + preflight_commitment: Some(CommitmentLevel::Confirmed), + ..Default::default() + }; + let cancel_signal_clone = Arc::clone(&cancel_signal); + let num_sent_transactions_clone = Arc::clone(&num_sent_transactions); + + async move { + if cancel_signal_clone.load(Ordering::SeqCst) || Instant::now() >= timeout_deadline { + return TransactionSendResult::Cancelled; // Or Timeout + } + + let tx_signature = tx.signatures.first().copied().unwrap_or_default(); + let tx_signature_str = tx_signature.to_string(); + + match pool_clone.get_connection().await { + Ok(mut rpc) => { + if Instant::now() >= timeout_deadline { + warn!(tx.signature = %tx_signature_str, "Timeout after getting RPC, before sending tx"); + return TransactionSendResult::Timeout; + } + + let send_time = Instant::now(); + match rpc.process_transaction_with_config(tx, rpc_send_config).await { + Ok(signature) => { + if !cancel_signal_clone.load(Ordering::SeqCst) { // Re-check before incrementing + num_sent_transactions_clone.fetch_add(1, Ordering::SeqCst); + trace!(tx.signature = %signature, elapsed = ?send_time.elapsed(), "Transaction sent successfully"); + TransactionSendResult::Success(signature) + } else { + trace!(tx.signature = %signature, "Transaction processed but run was cancelled post-send"); + TransactionSendResult::Cancelled + } + } + Err(e) => { + warn!(tx.signature = %tx_signature_str, error = ?e, "Transaction send/process failed"); + TransactionSendResult::Failure(ForesterError::from(e), Some(tx_signature)) + } + } + } + Err(e) => { + error!(tx.signature_attempt = %tx_signature_str, error = ?e, "Failed to get RPC connection for sending transaction"); + TransactionSendResult::Failure(ForesterError::from(e), Some(tx_signature)) + } + } + } + }); + + debug!( + "Executing batch of sends with concurrency limit {}", + max_concurrent_sends + ); + let exec_start = Instant::now(); + let results = futures::stream::iter(transaction_send_futures) + .buffer_unordered(max_concurrent_sends) // buffer_unordered for concurrency + .collect::>() + .await; + debug!("Finished executing batch in {:?}", exec_start.elapsed()); + + let mut successes = 0; + let mut failures = 0; + let mut cancelled_or_timeout = 0; + for outcome in results { + match outcome { + TransactionSendResult::Success(sig) => { + trace!(tx.signature = %sig, outcome = "SuccessInChunkSummary"); + successes += 1; + } + TransactionSendResult::Failure(err, opt_sig) => { + failures += 1; + if let Some(sig) = opt_sig { + trace!(tx.signature = %sig, error = ?err, outcome = "FailureInChunkSummary"); + } else { + trace!(error = ?err, outcome = "FailureInChunkSummary (no signature)"); + } + } + TransactionSendResult::Cancelled | TransactionSendResult::Timeout => { + cancelled_or_timeout += 1; + } + } + } + debug!( + "Chunk send summary: {} successes, {} failures, {} cancelled/timeout", + successes, failures, cancelled_or_timeout + ); +} diff --git a/forester/src/processor/v1/tx_builder.rs b/forester/src/processor/v1/tx_builder.rs new file mode 100644 index 0000000000..06c05939b8 --- /dev/null +++ b/forester/src/processor/v1/tx_builder.rs @@ -0,0 +1,151 @@ +use std::sync::Arc; + +use account_compression::processor::initialize_address_merkle_tree::Pubkey; +use async_trait::async_trait; +use light_client::{indexer::Indexer, rpc::RpcConnection, rpc_pool::SolanaRpcPool}; +use solana_program::hash::Hash; +use solana_sdk::{ + signature::{Keypair, Signer}, + transaction::Transaction, +}; +use tokio::sync::Mutex; +use tracing::{debug, warn}; + +use crate::{ + epoch_manager::WorkItem, + processor::{ + tx_cache::ProcessedHashCache, + v1::{config::BuildTransactionBatchConfig, helpers::fetch_proofs_and_create_instructions}, + }, + smart_transaction::{create_smart_transaction, CreateSmartTransactionConfig}, + Result, +}; + +#[async_trait] +#[allow(clippy::too_many_arguments)] +pub trait TransactionBuilder { + fn epoch(&self) -> u64; + async fn build_signed_transaction_batch( + &self, + payer: &Keypair, + derivation: &Pubkey, + recent_blockhash: &Hash, + last_valid_block_height: u64, + priority_fee: u64, + work_items: &[WorkItem], + config: BuildTransactionBatchConfig, + ) -> Result<(Vec, u64)>; +} + +pub struct EpochManagerTransactions> { + pub indexer: Arc>, + pub pool: Arc>, + pub epoch: u64, + pub phantom: std::marker::PhantomData, + pub processed_hash_cache: Arc>, +} + +impl> EpochManagerTransactions { + pub fn new( + indexer: Arc>, + pool: Arc>, + epoch: u64, + cache: Arc>, + ) -> Self { + Self { + indexer, + pool, + epoch, + phantom: std::marker::PhantomData, + processed_hash_cache: cache, + } + } +} + +#[async_trait] +impl> TransactionBuilder for EpochManagerTransactions { + fn epoch(&self) -> u64 { + self.epoch + } + + async fn build_signed_transaction_batch( + &self, + payer: &Keypair, + derivation: &Pubkey, + recent_blockhash: &Hash, + last_valid_block_height: u64, + priority_fee: u64, + work_items: &[WorkItem], + config: BuildTransactionBatchConfig, + ) -> Result<(Vec, u64)> { + let mut cache = self.processed_hash_cache.lock().await; + + let work_items: Vec<&WorkItem> = work_items + .iter() + .filter(|item| { + let hash_str = bs58::encode(&item.queue_item_data.hash).into_string(); + if cache.contains(&hash_str) { + debug!("Skipping already processed hash: {}", hash_str); + false + } else { + true + } + }) + .collect(); + + for item in &work_items { + let hash_str = bs58::encode(&item.queue_item_data.hash).into_string(); + cache.add(&hash_str); + } + drop(cache); + + if work_items.is_empty() { + debug!("All items in this batch were recently processed, skipping batch"); + return Ok((vec![], last_valid_block_height)); + } + + let work_items = work_items + .iter() + .map(|&item| item.clone()) + .collect::>(); + + let mut transactions = vec![]; + let all_instructions = match fetch_proofs_and_create_instructions( + payer.pubkey(), + *derivation, + self.pool.clone(), + self.indexer.clone(), + self.epoch, + work_items.as_slice(), + ) + .await + { + Ok((_, instructions)) => instructions, + Err(e) => { + // Check if it's a "Record Not Found" error + return if e.to_string().contains("Record Not Found") { + warn!("Record not found in indexer, skipping batch: {}", e); + // Return empty transactions but don't propagate the error + Ok((vec![], last_valid_block_height)) + } else { + // For any other error, propagate it + Err(e) + }; + } + }; + + for instruction in all_instructions { + let (transaction, _) = create_smart_transaction(CreateSmartTransactionConfig { + payer: payer.insecure_clone(), + instructions: vec![instruction], + recent_blockhash: *recent_blockhash, + compute_unit_price: Some(priority_fee), + compute_unit_limit: config.compute_unit_limit, + last_valid_block_hash: last_valid_block_height, + }) + .await?; + transactions.push(transaction); + } + Ok((transactions, last_valid_block_height)) + } +} diff --git a/forester/src/batch_processor/address.rs b/forester/src/processor/v2/address.rs similarity index 94% rename from forester/src/batch_processor/address.rs rename to forester/src/processor/v2/address.rs index 1b11aa5c6f..b9212d5349 100644 --- a/forester/src/batch_processor/address.rs +++ b/forester/src/processor/v2/address.rs @@ -6,14 +6,14 @@ use light_registry::account_compression_cpi::sdk::create_batch_update_address_tr use solana_sdk::signer::Signer; use tracing::{debug, info, instrument, log::error}; -use super::common::BatchContext; -use crate::{ - batch_processor::error::{BatchProcessError, Result}, - indexer_type::{finalize_batch_address_tree_update, IndexerType}, +use super::{ + common::BatchContext, + error::{BatchProcessError, Result}, }; +use crate::indexer_type::{finalize_batch_address_tree_update, IndexerType}; #[instrument(level = "debug", skip(context), fields(tree = %context.merkle_tree))] -pub(crate) async fn process_batch + IndexerType>( +pub async fn process_batch + IndexerType>( context: &BatchContext, ) -> Result { info!("Processing address batch operation"); diff --git a/forester/src/batch_processor/common.rs b/forester/src/processor/v2/common.rs similarity index 97% rename from forester/src/batch_processor/common.rs rename to forester/src/processor/v2/common.rs index 732e20f8e4..3dd9690893 100644 --- a/forester/src/batch_processor/common.rs +++ b/forester/src/processor/v2/common.rs @@ -10,7 +10,7 @@ use light_compressed_account::TreeType; use solana_program::pubkey::Pubkey; use solana_sdk::signature::Keypair; use tokio::sync::Mutex; -use tracing::{debug, info, log::error}; +use tracing::{debug, error, trace, warn}; use super::{address, error::Result, state, BatchProcessError}; use crate::indexer_type::IndexerType; @@ -46,18 +46,17 @@ impl + IndexerType> BatchProcessor { } pub async fn process(&self) -> Result { - info!( + trace!( "Starting batch processing for tree type: {:?}", self.tree_type ); let state = self.verify_batch_ready().await; - debug!("Batch ready state: {:?}", state); match state { BatchReadyState::ReadyForAppend => match self.tree_type { TreeType::AddressV2 => address::process_batch(&self.context).await, TreeType::StateV2 => { - info!( + trace!( "Process state append for tree: {}", self.context.merkle_tree ); @@ -76,7 +75,7 @@ impl + IndexerType> BatchProcessor { } }, BatchReadyState::ReadyForNullify => { - info!( + trace!( "Processing batch for nullify, tree: {}", self.context.merkle_tree ); @@ -90,7 +89,7 @@ impl + IndexerType> BatchProcessor { result } BatchReadyState::NotReady => { - debug!( + warn!( "Batch not ready for processing, tree: {}", self.context.merkle_tree ); @@ -133,9 +132,10 @@ impl + IndexerType> BatchProcessor { let input_fill = self.get_input_queue_completion(&mut rpc).await; let output_fill = self.get_output_queue_completion(&mut rpc).await; - debug!( + trace!( "Input queue fill: {:.2}, Output queue fill: {:.2}", - input_fill, output_fill + input_fill, + output_fill ); if input_fill > output_fill { BatchReadyState::ReadyForNullify diff --git a/forester/src/batch_processor/error.rs b/forester/src/processor/v2/error.rs similarity index 100% rename from forester/src/batch_processor/error.rs rename to forester/src/processor/v2/error.rs diff --git a/forester/src/batch_processor/mod.rs b/forester/src/processor/v2/mod.rs similarity index 90% rename from forester/src/batch_processor/mod.rs rename to forester/src/processor/v2/mod.rs index 4e36b495c1..57efd816ad 100644 --- a/forester/src/batch_processor/mod.rs +++ b/forester/src/processor/v2/mod.rs @@ -6,7 +6,7 @@ mod state; use common::BatchProcessor; use error::Result; use light_client::rpc::RpcConnection; -use tracing::{debug, instrument}; +use tracing::{instrument, trace}; #[instrument( level = "debug", @@ -21,7 +21,7 @@ pub async fn process_batched_operations + Indexe context: BatchContext, tree_type: TreeType, ) -> Result { - debug!("process_batched_operations"); + trace!("process_batched_operations"); let processor = BatchProcessor::new(context, tree_type); processor.process().await } diff --git a/forester/src/batch_processor/state.rs b/forester/src/processor/v2/state.rs similarity index 94% rename from forester/src/batch_processor/state.rs rename to forester/src/processor/v2/state.rs index 0e1582de7d..3793611c68 100644 --- a/forester/src/batch_processor/state.rs +++ b/forester/src/processor/v2/state.rs @@ -10,12 +10,12 @@ use light_registry::account_compression_cpi::sdk::{ use solana_sdk::signer::Signer; use tracing::{debug, info, instrument, log::error}; -use super::common::BatchContext; -use crate::{ - batch_processor::error::{BatchProcessError, Result}, - indexer_type::{ - update_test_indexer_after_append, update_test_indexer_after_nullification, IndexerType, - }, +use super::{ + common::BatchContext, + error::{BatchProcessError, Result}, +}; +use crate::indexer_type::{ + update_test_indexer_after_append, update_test_indexer_after_nullification, IndexerType, }; #[instrument( @@ -27,7 +27,7 @@ use crate::{ output_queue = %context.output_queue, ), skip(context, rpc)) ] -pub(crate) async fn perform_append + IndexerType>( +pub async fn perform_append + IndexerType>( context: &BatchContext, rpc: &mut R, ) -> Result<()> { @@ -136,7 +136,7 @@ pub(crate) async fn perform_append + IndexerType ), skip(context, rpc) )] -pub(crate) async fn perform_nullify + IndexerType>( +pub async fn perform_nullify + IndexerType>( context: &BatchContext, rpc: &mut R, ) -> Result<()> { diff --git a/forester/src/rollover/operations.rs b/forester/src/rollover/operations.rs index a7b2d6f493..e3744bcc94 100644 --- a/forester/src/rollover/operations.rs +++ b/forester/src/rollover/operations.rs @@ -289,7 +289,7 @@ pub async fn perform_state_merkle_tree_rollover_forester( epoch, ) .await; - let blockhash = context.get_latest_blockhash().await.unwrap(); + let blockhash = context.get_latest_blockhash().await?; let transaction = Transaction::new_signed_with_payer( &instructions, Some(&payer.pubkey()), @@ -299,7 +299,7 @@ pub async fn perform_state_merkle_tree_rollover_forester( &new_address_merkle_tree_keypair, &new_cpi_context_keypair, ], - blockhash, + blockhash.0, ); context.process_transaction(transaction).await } @@ -328,12 +328,12 @@ pub async fn perform_address_merkle_tree_rollover( .await; let compute_budget_instruction = ComputeBudgetInstruction::set_compute_unit_limit(500_000); instructions.insert(0, compute_budget_instruction); - let blockhash = context.get_latest_blockhash().await.unwrap(); + let blockhash = context.get_latest_blockhash().await?; let transaction = Transaction::new_signed_with_payer( &instructions, Some(&payer.pubkey()), &vec![&payer, &new_queue_keypair, &new_address_merkle_tree_keypair], - blockhash, + blockhash.0, ); context.process_transaction(transaction).await } @@ -483,7 +483,7 @@ pub async fn get_rent_exemption_for_state_merkle_tree_and_queue u64; - async fn build_signed_transaction_batch( - &self, - payer: &Keypair, - derivation: &Pubkey, - recent_blockhash: &Hash, - last_valid_block_height: u64, - priority_fee: u64, - work_items: &[WorkItem], - config: BuildTransactionBatchConfig, - ) -> Result<(Vec, u64)>; -} - -#[derive(Debug, Clone, Copy)] -pub struct CapConfig { - pub rec_fee_microlamports_per_cu: u64, - pub min_fee_lamports: u64, - pub max_fee_lamports: u64, - pub compute_unit_limit: u64, -} - -#[derive(Debug, Clone, Copy)] -pub struct SendBatchedTransactionsConfig { - pub num_batches: u64, - pub build_transaction_batch_config: BuildTransactionBatchConfig, - pub queue_config: QueueConfig, - pub retry_config: RetryConfig, - pub light_slot_length: u64, -} - -#[derive(Debug, Clone, Copy)] -pub struct BuildTransactionBatchConfig { - pub batch_size: u64, - pub compute_unit_price: Option, - pub compute_unit_limit: Option, - pub enable_priority_fees: bool, -} - -#[derive(Debug, Clone)] -pub struct ProcessedHashCache { - entries: HashMap, - ttl: Duration, -} - -impl ProcessedHashCache { - pub fn new(ttl_seconds: u64) -> Self { - Self { - entries: HashMap::new(), - ttl: Duration::from_secs(ttl_seconds), - } - } - - fn add(&mut self, hash: &str) { - self.entries.insert(hash.to_string(), Instant::now()); - } - - fn contains(&mut self, hash: &str) -> bool { - self.cleanup(); - self.entries.contains_key(hash) - } - - fn cleanup(&mut self) { - let now = Instant::now(); - self.entries - .retain(|_, timestamp| now.duration_since(*timestamp) < self.ttl); - } -} - -/// Calculate the compute unit price in microLamports based on the target lamports and compute units -pub fn calculate_compute_unit_price(target_lamports: u64, compute_units: u64) -> u64 { - ((target_lamports * 1_000_000) as f64 / compute_units as f64).ceil() as u64 -} - -/// Setting: -/// 1. We have 1 light slot (n solana slots), and elements in the queue -/// 2. we want to send as many elements from the queue as possible -/// -/// Strategy: -/// 1. Execute transaction batches until max number of batches is -/// reached or light slot ended (global timeout). -/// 2. Fetch queue items. -/// 3. If work items is empty, await minimum batch time. -/// 4. Fetch recent blockhash. -/// 5. Iterate over work items in chunks of batch size. -/// 6. Check if we reached the end of the light slot. -/// 7. Asynchronously send all transactions in the batch -/// 8. Await minimum batch time. -/// 9. Check if we reached max number of batches. -/// -/// Questions: -/// - How do we make sure that we have send all the transactions? -/// -/// TODO: -/// - return number of sent transactions -/// - test timeout for any action of this function or subfunctions, timeout is -/// end of slot -/// - consider dynamic batch size based on the number of transactions in the -/// queue -pub async fn send_batched_transactions( - payer: &Keypair, - derivation: &Pubkey, - pool: Arc>, - config: &SendBatchedTransactionsConfig, - tree_accounts: TreeAccounts, - transaction_builder: &T, -) -> Result { - let start_time = Instant::now(); - let tree_id_str = tree_accounts.merkle_tree.to_string(); - let queue_id_str = tree_accounts.queue.to_string(); - - let num_sent_transactions = Arc::new(AtomicUsize::new(0)); - let cancel_signal = Arc::new(AtomicBool::new(false)); - - let queue_length = if tree_accounts.tree_type == TreeType::StateV1 { - STATE_NULLIFIER_QUEUE_VALUES - } else { - ADDRESS_QUEUE_VALUES - }; - - let start_index = if tree_accounts.tree_type == TreeType::StateV1 { - config.queue_config.state_queue_start_index - } else { - config.queue_config.address_queue_start_index - }; - - let length = if tree_accounts.tree_type == TreeType::StateV1 { - config.queue_config.state_queue_length - } else { - config.queue_config.address_queue_length - }; - - let queue_item_data = { - let mut rpc = pool.get_connection().await?; - - fetch_queue_item_data( - &mut *rpc, - &tree_accounts.queue, - start_index, - length, - queue_length, - ) - .await? - }; - - if queue_item_data.is_empty() { - debug!("{} Queue is empty, no transactions to send.", tree_id_str); - return Ok(0); - } - - let (recent_blockhash, current_block_height) = { - let mut rpc = pool.get_connection().await?; - ( - rpc.get_latest_blockhash().await?, - rpc.get_block_height().await?, - ) - }; - let last_valid_block_height = current_block_height + 150; - - let priority_fee = if config.build_transaction_batch_config.enable_priority_fees { - let rpc = pool.get_connection().await?; - let forester_epoch_pda_pubkey = - get_forester_epoch_pda_from_authority(derivation, transaction_builder.epoch()).0; - - let account_keys = vec![ - payer.pubkey(), - forester_epoch_pda_pubkey, - tree_accounts.queue, - tree_accounts.merkle_tree, - ]; - let url = Url::parse(&rpc.get_url()).expect("Failed to parse URL"); - request_priority_fee_estimate(&url, account_keys).await? - } else { - 10_000 // Minimum priority fee when disabled - }; - - let work_items: Vec = queue_item_data - .into_iter() - .map(|data| WorkItem { - tree_account: tree_accounts, - queue_item_data: data, - }) - .collect(); - - let timeout_deadline = start_time + config.retry_config.timeout; - - const MAX_CONCURRENT_SENDS: usize = 1; - info!(tree = %tree_id_str, "Starting transaction sending loop. Timeout deadline: {:?}. Max concurrent sends: {}", timeout_deadline, MAX_CONCURRENT_SENDS); - - for work_chunk in work_items.chunks(config.build_transaction_batch_config.batch_size as usize) { - if cancel_signal.load(Ordering::SeqCst) { - debug!(tree = %tree_id_str, "Cancellation signal received, stopping batch processing."); - break; - } - if Instant::now() >= timeout_deadline { - warn!(tree = %tree_id_str, "Reached timeout deadline before processing next chunk, stopping."); - break; - } - debug!(tree = %tree_id_str, "Processing chunk of size {}", work_chunk.len()); - let build_start = Instant::now(); - let (transactions, _obtained_last_valid_block_height) = match transaction_builder - .build_signed_transaction_batch( - payer, - derivation, - &recent_blockhash, - last_valid_block_height, - priority_fee, - work_chunk, - config.build_transaction_batch_config, - ) - .await - { - Ok(res) => res, - Err(e) => { - error!(tree = %tree_id_str, "Failed to build transaction batch: {:?}", e); - cancel_signal.store(true, Ordering::SeqCst); - break; - } - }; - debug!(tree = %tree_id_str, "Built {} transactions in {:?}", transactions.len(), build_start.elapsed()); - - if Instant::now() >= timeout_deadline { - warn!(tree = %tree_id_str, "Reached timeout deadline after building transactions, stopping chunk processing."); - break; - } - if transactions.is_empty() { - debug!(tree = %tree_id_str, "Built batch resulted in 0 transactions, skipping send."); - continue; - } - let transaction_stream = iter(transactions); - - let send_futures_stream = transaction_stream.map(|tx| { - let pool_clone = pool.clone(); - let rpc_send_config = RpcSendTransactionConfig { - skip_preflight: true, - max_retries: Some(0), - preflight_commitment: Some(CommitmentLevel::Confirmed), - ..Default::default() - }; - let cancel_signal_clone = cancel_signal.clone(); - let num_sent_transactions_clone = num_sent_transactions.clone(); - let deadline = timeout_deadline; - let tree_id_str_clone = tree_id_str.clone(); - let queue_id_str_clone = queue_id_str.clone(); - - async move { - if cancel_signal_clone.load(Ordering::SeqCst) || Instant::now() >= deadline { - return; - } - - let tx_signature = tx.signatures.first().copied().unwrap_or_default(); - let tx_signature_str = tx_signature.to_string(); - let context_str = format!("send_batched_transactions (concurrent sender), tree: {}, tx_sig_prefix: {}", tree_id_str_clone, &tx_signature_str[..8]); - - let rpc_result = pool_clone.get_connection().await; - match rpc_result { - Ok(mut rpc) => { - if Instant::now() >= deadline { - warn!(context = %context_str, "Reached timeout deadline after getting connection, skipping send"); - return; - } - - let result = rpc.process_transaction_with_config(tx, rpc_send_config).await; - - if !cancel_signal_clone.load(Ordering::SeqCst) { - match result { - Ok(signature) => { - num_sent_transactions_clone.fetch_add(1, Ordering::SeqCst); - debug!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %signature, "Transaction sent successfully"); - } - Err(e) => { - warn!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %tx_signature_str, "Transaction send/process failed: {:?}", e); - match pool_clone.get_connection().await { - Ok(check_rpc) => { - if !check_rpc.should_retry(&e) { - warn!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %tx_signature_str, "Non-retryable RPC error detected, setting cancel signal: {:?}", e); - cancel_signal_clone.store(true, Ordering::SeqCst); - } else { - debug!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %tx_signature_str, "Retryable RPC error encountered: {:?}", e); - } - } - Err(pool_err) => { - warn!(tree = %tree_id_str_clone, queue = %queue_id_str_clone, tx = %tx_signature_str, "Failed to get RPC connection for retry check: {}", pool_err); - cancel_signal_clone.store(true, Ordering::SeqCst); - } - } - } - } - } else { - debug!(context = %context_str, "Cancelled during transaction processing, discarding result."); - } - } - Err(ref e) => { - error!(context = %context_str, "Failed to get RPC connection: {:?}", e) - } - } - } - }); - - debug!(tree = %tree_id_str, "Executing batch of {} sends with concurrency limit {}", work_chunk.len(), MAX_CONCURRENT_SENDS); - let exec_start = Instant::now(); - send_futures_stream - .for_each_concurrent(MAX_CONCURRENT_SENDS, |f| f) - .await; - debug!(tree = %tree_id_str, "Finished executing batch in {:?}", exec_start.elapsed()); - } - - debug!(tree = %tree_id_str, "Transaction sending loop finished. Total transactions sent attempt count: {}", num_sent_transactions.load(Ordering::Relaxed)); - Ok(num_sent_transactions.load(Ordering::SeqCst)) -} - -pub struct EpochManagerTransactions> { - pub indexer: Arc>, - pub pool: Arc>, - pub epoch: u64, - pub phantom: std::marker::PhantomData, - pub processed_hash_cache: Arc>, -} - -impl> EpochManagerTransactions { - pub fn new( - indexer: Arc>, - pool: Arc>, - epoch: u64, - cache: Arc>, - ) -> Self { - Self { - indexer, - pool, - epoch, - phantom: std::marker::PhantomData, - processed_hash_cache: cache, - } - } -} - -#[async_trait] -impl> TransactionBuilder for EpochManagerTransactions { - fn epoch(&self) -> u64 { - self.epoch - } - - async fn build_signed_transaction_batch( - &self, - payer: &Keypair, - derivation: &Pubkey, - recent_blockhash: &Hash, - last_valid_block_height: u64, - priority_fee: u64, - work_items: &[WorkItem], - config: BuildTransactionBatchConfig, - ) -> Result<(Vec, u64)> { - let mut cache = self.processed_hash_cache.lock().await; - - let work_items: Vec<&WorkItem> = work_items - .iter() - .filter(|item| { - let hash_str = bs58::encode(&item.queue_item_data.hash).into_string(); - if cache.contains(&hash_str) { - debug!("Skipping already processed hash: {}", hash_str); - false - } else { - true - } - }) - .collect(); - - for item in &work_items { - let hash_str = bs58::encode(&item.queue_item_data.hash).into_string(); - cache.add(&hash_str); - } - drop(cache); - - if work_items.is_empty() { - debug!("All items in this batch were recently processed, skipping batch"); - return Ok((vec![], last_valid_block_height)); - } - - let work_items = work_items - .iter() - .map(|&item| item.clone()) - .collect::>(); - - let mut transactions = vec![]; - let all_instructions = match fetch_proofs_and_create_instructions( - payer.pubkey(), - *derivation, - self.pool.clone(), - self.indexer.clone(), - self.epoch, - work_items.as_slice(), - ) - .await - { - Ok((_, instructions)) => instructions, - Err(e) => { - // Check if it's a "Record Not Found" error - return if e.to_string().contains("Record Not Found") { - warn!("Record not found in indexer, skipping batch: {}", e); - // Return empty transactions but don't propagate the error - Ok((vec![], last_valid_block_height)) - } else { - // For any other error, propagate it - Err(e) - }; - } - }; - - for instruction in all_instructions { - let (transaction, _) = create_smart_transaction(CreateSmartTransactionConfig { - payer: payer.insecure_clone(), - instructions: vec![instruction], - recent_blockhash: *recent_blockhash, - compute_unit_price: Some(priority_fee), - compute_unit_limit: config.compute_unit_limit, - last_valid_block_hash: last_valid_block_height, - }) - .await?; - transactions.push(transaction); - } - Ok((transactions, last_valid_block_height)) - } -} - -/// Work items should be of only one type and tree -pub async fn fetch_proofs_and_create_instructions>( - authority: Pubkey, - derivation: Pubkey, - pool: Arc>, - indexer: Arc>, - epoch: u64, - work_items: &[WorkItem], -) -> Result<(Vec, Vec)> { - let mut proofs = Vec::new(); - let mut instructions = vec![]; - - let (address_items, state_items): (Vec<_>, Vec<_>) = work_items - .iter() - .partition(|item| matches!(item.tree_account.tree_type, TreeType::AddressV1)); - - for item in state_items.iter() { - if item.tree_account.tree_type != TreeType::StateV1 { - warn!( - "State item has unexpected tree type: {:?}", - item.tree_account.tree_type - ); - } - } - let state_items = state_items - .into_iter() - .filter(|item| item.tree_account.tree_type == TreeType::StateV1) - .collect::>(); - - let address_data = if !address_items.is_empty() { - let merkle_tree = address_items - .first() - .ok_or_else(|| ForesterError::General { - error: "No address items found".to_string(), - })? - .tree_account - .merkle_tree - .to_bytes(); - let addresses: Vec<[u8; 32]> = address_items - .iter() - .map(|item| item.queue_item_data.hash) - .collect(); - Some((merkle_tree, addresses)) - } else { - None - }; - - let state_data = if !state_items.is_empty() { - let states: Vec = state_items - .iter() - .map(|item| bs58::encode(&item.queue_item_data.hash).into_string()) - .collect(); - Some(states) - } else { - None - }; - - let indexer_guard = indexer.lock().await; - let mut rpc = pool - .get_connection() - .await?; - - if let Err(e) = wait_for_indexer(&mut *rpc, &*indexer_guard).await { - warn!("Indexer not fully caught up, but proceeding anyway: {}", e); - } - - let (address_proofs_result, state_proofs_result) = { - let address_future = async { - if let Some((merkle_tree, addresses)) = address_data { - indexer_guard - .get_multiple_new_address_proofs(merkle_tree, addresses) - .await - } else { - Ok(vec![]) - } - }; - - let state_future = async { - if let Some(states) = state_data { - indexer_guard - .get_multiple_compressed_account_proofs(states) - .await - } else { - Ok(vec![]) - } - }; - - join!(address_future, state_future) - }; - - let address_proofs = match address_proofs_result { - Ok(proofs) => proofs, - Err(e) => { - return Err(anyhow::anyhow!("Failed to get address proofs: {}", e)); - } - }; - - let state_proofs = match state_proofs_result { - Ok(proofs) => proofs, - Err(e) => { - return Err(anyhow::anyhow!("Failed to get state proofs: {}", e)); - } - }; - - for (item, proof) in address_items.iter().zip(address_proofs.into_iter()) { - proofs.push(MerkleProofType::AddressProof(proof.clone())); - let instruction = create_update_address_merkle_tree_instruction( - UpdateAddressMerkleTreeInstructionInputs { - authority, - derivation, - address_merkle_tree: item.tree_account.merkle_tree, - address_queue: item.tree_account.queue, - value: item.queue_item_data.index as u16, - low_address_index: proof.low_address_index, - low_address_value: proof.low_address_value, - low_address_next_index: proof.low_address_next_index, - low_address_next_value: proof.low_address_next_value, - low_address_proof: proof.low_address_proof, - changelog_index: (proof.root_seq % ADDRESS_MERKLE_TREE_CHANGELOG) as u16, - indexed_changelog_index: (proof.root_seq % ADDRESS_MERKLE_TREE_INDEXED_CHANGELOG) - as u16, - is_metadata_forester: false, - }, - epoch, - ); - instructions.push(instruction); - } - - // Process state proofs and create instructions - for (item, proof) in state_items.iter().zip(state_proofs.into_iter()) { - proofs.push(MerkleProofType::StateProof(proof.clone())); - let instruction = create_nullify_instruction( - CreateNullifyInstructionInputs { - nullifier_queue: item.tree_account.queue, - merkle_tree: item.tree_account.merkle_tree, - change_log_indices: vec![proof.root_seq % STATE_MERKLE_TREE_CHANGELOG], - leaves_queue_indices: vec![item.queue_item_data.index as u16], - indices: vec![proof.leaf_index], - proofs: vec![proof.proof.clone()], - authority, - derivation, - is_metadata_forester: false, - }, - epoch, - ); - instructions.push(instruction); - } - - Ok((proofs, instructions)) -} - -/// Request priority fee estimate from Helius RPC endpoint -pub async fn request_priority_fee_estimate(url: &Url, account_keys: Vec) -> Result { - if url.host_str() != Some("mainnet") { - return Ok(10_000); - } - - let priority_fee_request = GetPriorityFeeEstimateRequest { - transaction: None, - account_keys: Some( - account_keys - .iter() - .map(|pubkey| bs58::encode(pubkey).into_string()) - .collect(), - ), - options: Some(GetPriorityFeeEstimateOptions { - include_all_priority_fee_levels: None, - recommended: Some(true), - include_vote: None, - lookback_slots: None, - priority_level: None, - transaction_encoding: None, - }), - }; - - let rpc_request = RpcRequest::new( - "getPriorityFeeEstimate".to_string(), - serde_json::json!({ - "get_priority_fee_estimate_request": priority_fee_request - }), - ); - - let client = reqwest::Client::new(); - let response = client - .post(url.clone()) - .header("Content-Type", "application/json") - .json(&rpc_request) - .send() - .await?; - - let response_text = response.text().await?; - - let response: RpcResponse = - serde_json::from_str(&response_text)?; - - response - .result - .priority_fee_estimate - .map(|estimate| estimate as u64) - .ok_or( - ForesterError::General { - error: "Priority fee estimate not available".to_string(), - } - .into(), - ) -} - -/// Get a capped priority fee for transaction between min and max. -pub fn get_capped_priority_fee(cap_config: CapConfig) -> u64 { - if cap_config.max_fee_lamports < cap_config.min_fee_lamports { - panic!("Max fee is less than min fee"); - } - - let priority_fee_max = - calculate_compute_unit_price(cap_config.max_fee_lamports, cap_config.compute_unit_limit); - let priority_fee_min = - calculate_compute_unit_price(cap_config.min_fee_lamports, cap_config.compute_unit_limit); - let capped_fee = std::cmp::min(cap_config.rec_fee_microlamports_per_cu, priority_fee_max); - std::cmp::max(capped_fee, priority_fee_min) -} diff --git a/forester/tests/priority_fee_test.rs b/forester/tests/priority_fee_test.rs index 19a313c3df..6eaf3924c2 100644 --- a/forester/tests/priority_fee_test.rs +++ b/forester/tests/priority_fee_test.rs @@ -1,6 +1,9 @@ use forester::{ cli::StartArgs, - send_transaction::{get_capped_priority_fee, request_priority_fee_estimate, CapConfig}, + processor::v1::{ + config::CapConfig, + helpers::{get_capped_priority_fee, request_priority_fee_estimate}, + }, ForesterConfig, }; use light_client::rpc::{RpcConnection, SolanaRpcConnection}; diff --git a/program-tests/compressed-token-test/tests/test.rs b/program-tests/compressed-token-test/tests/test.rs index eacffda319..f460092980 100644 --- a/program-tests/compressed-token-test/tests/test.rs +++ b/program-tests/compressed-token-test/tests/test.rs @@ -5344,7 +5344,7 @@ async fn perform_transfer_failing_test( ) .unwrap(); - let latest_blockhash = rpc.get_latest_blockhash().await.unwrap(); + let latest_blockhash = rpc.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&payer.pubkey()), diff --git a/program-tests/system-cpi-test/tests/test.rs b/program-tests/system-cpi-test/tests/test.rs index f74a91f8b3..47bbf9426d 100644 --- a/program-tests/system-cpi-test/tests/test.rs +++ b/program-tests/system-cpi-test/tests/test.rs @@ -1593,7 +1593,7 @@ pub async fn perform_create_pda_failing< &[instruction], Some(&payer_pubkey), &[&payer], - rpc.get_latest_blockhash().await.unwrap(), + rpc.get_latest_blockhash().await.unwrap().0, ); let result = rpc.process_transaction(transaction).await; assert_rpc_error(result, 0, expected_error_code) diff --git a/program-tests/system-cpi-test/tests/test_program_owned_trees.rs b/program-tests/system-cpi-test/tests/test_program_owned_trees.rs index bad8cb62d9..d8484f33f2 100644 --- a/program-tests/system-cpi-test/tests/test_program_owned_trees.rs +++ b/program-tests/system-cpi-test/tests/test_program_owned_trees.rs @@ -163,7 +163,7 @@ async fn test_program_owned_merkle_tree() { 0, ); - let latest_blockhash = rpc.get_latest_blockhash().await.unwrap(); + let latest_blockhash = rpc.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&payer_pubkey), @@ -790,7 +790,7 @@ pub async fn create_state_merkle_tree_and_queue_account( ], Some(&payer.pubkey()), &vec![payer, merkle_tree_keypair, nullifier_queue_keypair], - rpc.get_latest_blockhash().await.unwrap(), + rpc.get_latest_blockhash().await.unwrap().0, ); rpc.process_transaction(transaction.clone()).await } @@ -851,7 +851,7 @@ pub async fn create_address_merkle_tree_and_queue_account( &[account_create_ix, mt_account_create_ix, instruction], Some(&payer.pubkey()), &vec![&payer, &address_queue_keypair, &address_merkle_tree_keypair], - context.get_latest_blockhash().await.unwrap(), + context.get_latest_blockhash().await.unwrap().0, ); context.process_transaction(transaction.clone()).await } diff --git a/program-tests/system-test/tests/test.rs b/program-tests/system-test/tests/test.rs index 3b58588a92..7f2ec07063 100644 --- a/program-tests/system-test/tests/test.rs +++ b/program-tests/system-test/tests/test.rs @@ -1235,7 +1235,7 @@ async fn test_with_address() { &[instruction], Some(&payer_pubkey), &[&payer], - context.get_latest_blockhash().await.unwrap(), + context.get_latest_blockhash().await.unwrap().0, ); let res = context.process_transaction(transaction).await; @@ -1280,7 +1280,7 @@ async fn test_with_address() { &[instruction], Some(&payer_pubkey), &[&payer], - context.get_latest_blockhash().await.unwrap(), + context.get_latest_blockhash().await.unwrap().0, ); let res = context.process_transaction(transaction).await; @@ -1327,7 +1327,7 @@ async fn test_with_address() { &[instruction], Some(&payer_pubkey), &[&payer], - context.get_latest_blockhash().await.unwrap(), + context.get_latest_blockhash().await.unwrap().0, ); let res = context.process_transaction(transaction).await; @@ -1519,7 +1519,7 @@ async fn test_with_compression() { &[instruction], Some(&payer_pubkey), &[&payer], - context.get_latest_blockhash().await.unwrap(), + context.get_latest_blockhash().await.unwrap().0, ); let result = context.process_transaction(transaction).await; @@ -1552,7 +1552,7 @@ async fn test_with_compression() { &[instruction], Some(&payer_pubkey), &[&payer], - context.get_latest_blockhash().await.unwrap(), + context.get_latest_blockhash().await.unwrap().0, ); let result = context.process_transaction(transaction).await; @@ -1624,7 +1624,7 @@ async fn test_with_compression() { &[instruction], Some(&payer_pubkey), &[&payer], - context.get_latest_blockhash().await.unwrap(), + context.get_latest_blockhash().await.unwrap().0, ); println!("Transaction with zkp -------------------------"); diff --git a/program-tests/utils/src/address.rs b/program-tests/utils/src/address.rs index a8b466a168..8760152236 100644 --- a/program-tests/utils/src/address.rs +++ b/program-tests/utils/src/address.rs @@ -54,12 +54,12 @@ pub async fn insert_addresses( .concat(), data: instruction_data.data(), }; - let latest_blockhash = context.get_latest_blockhash().await.unwrap(); + let latest_blockhash = context.get_latest_blockhash().await?; let transaction = Transaction::new_signed_with_payer( &[insert_ix], Some(&context.get_payer().pubkey()), &[&context.get_payer()], - latest_blockhash, + latest_blockhash.0, ); context.process_transaction(transaction).await } diff --git a/program-tests/utils/src/address_tree_rollover.rs b/program-tests/utils/src/address_tree_rollover.rs index 74b7354ca9..cfa0f06314 100644 --- a/program-tests/utils/src/address_tree_rollover.rs +++ b/program-tests/utils/src/address_tree_rollover.rs @@ -115,7 +115,7 @@ pub async fn perform_address_merkle_tree_roll_over( accounts: [accounts.to_account_metas(Some(true))].concat(), data: instruction_data.data(), }; - let blockhash = context.get_latest_blockhash().await.unwrap(); + let blockhash = context.get_latest_blockhash().await?; let transaction = Transaction::new_signed_with_payer( &[account_create_ix, mt_account_create_ix, instruction], Some(&context.get_payer().pubkey()), @@ -124,7 +124,7 @@ pub async fn perform_address_merkle_tree_roll_over( &new_queue_keypair, &new_address_merkle_tree_keypair, ], - blockhash, + blockhash.0, ); context.process_transaction(transaction).await } @@ -301,12 +301,12 @@ pub async fn perform_address_merkle_tree_roll_over_forester( is_metadata_forester, ) .await; - let blockhash = context.get_latest_blockhash().await.unwrap(); + let blockhash = context.get_latest_blockhash().await?; let transaction = Transaction::new_signed_with_payer( &instructions, Some(&payer.pubkey()), &vec![&payer, &new_queue_keypair, &new_address_merkle_tree_keypair], - blockhash, + blockhash.0, ); context.process_transaction(transaction).await } @@ -336,7 +336,7 @@ pub async fn perform_state_merkle_tree_roll_over_forester( is_metadata_forester, ) .await; - let blockhash = context.get_latest_blockhash().await.unwrap(); + let blockhash = context.get_latest_blockhash().await?; let transaction = Transaction::new_signed_with_payer( &instructions, Some(&payer.pubkey()), @@ -346,7 +346,7 @@ pub async fn perform_state_merkle_tree_roll_over_forester( &new_address_merkle_tree_keypair, &new_cpi_signature_keypair, ], - blockhash, + blockhash.0, ); context.process_transaction_with_context(transaction).await } diff --git a/program-tests/utils/src/state_tree_rollover.rs b/program-tests/utils/src/state_tree_rollover.rs index 4416da7616..52524e55d6 100644 --- a/program-tests/utils/src/state_tree_rollover.rs +++ b/program-tests/utils/src/state_tree_rollover.rs @@ -100,7 +100,7 @@ pub async fn perform_state_merkle_tree_roll_over( .concat(), data: instruction_data.data(), }; - let blockhash = rpc.get_latest_blockhash().await.unwrap(); + let blockhash = rpc.get_latest_blockhash().await?; let transaction = Transaction::new_signed_with_payer( &[ create_nullifier_queue_instruction, @@ -113,7 +113,7 @@ pub async fn perform_state_merkle_tree_roll_over( &new_nullifier_queue_keypair, &new_state_merkle_tree_keypair, ], - blockhash, + blockhash.0, ); rpc.process_transaction_with_context(transaction).await } diff --git a/sdk-libs/client/src/rpc/rpc_connection.rs b/sdk-libs/client/src/rpc/rpc_connection.rs index fd28d6570d..6e0c828967 100644 --- a/sdk-libs/client/src/rpc/rpc_connection.rs +++ b/sdk-libs/client/src/rpc/rpc_connection.rs @@ -50,7 +50,7 @@ pub trait RpcConnection: Send + Sync + Debug + 'static { } } - async fn check_send_tx_rrate_limit(&self) { + async fn check_send_tx_rate_limit(&self) { if let Some(limiter) = self.send_tx_rate_limiter() { limiter.acquire_with_wait().await; } @@ -98,7 +98,7 @@ pub trait RpcConnection: Send + Sync + Debug + 'static { payer: &'a Pubkey, signers: &'a [&'a Keypair], ) -> Result { - let blockhash = self.get_latest_blockhash().await?; + let blockhash = self.get_latest_blockhash().await?.0; let transaction = Transaction::new_signed_with_payer(instructions, Some(payer), signers, blockhash); self.process_transaction(transaction).await @@ -128,7 +128,7 @@ pub trait RpcConnection: Send + Sync + Debug + 'static { } async fn get_balance(&mut self, pubkey: &Pubkey) -> Result; - async fn get_latest_blockhash(&mut self) -> Result; + async fn get_latest_blockhash(&mut self) -> Result<(Hash, u64), RpcError>; async fn get_slot(&mut self) -> Result; async fn warp_to_slot(&mut self, slot: Slot) -> Result<(), RpcError>; async fn send_transaction(&self, transaction: &Transaction) -> Result; diff --git a/sdk-libs/client/src/rpc/solana_rpc.rs b/sdk-libs/client/src/rpc/solana_rpc.rs index 3653ed6840..f78ca1c17e 100644 --- a/sdk-libs/client/src/rpc/solana_rpc.rs +++ b/sdk-libs/client/src/rpc/solana_rpc.rs @@ -520,13 +520,12 @@ impl RpcConnection for SolanaRpcConnection { .await } - async fn get_latest_blockhash(&mut self) -> Result { + async fn get_latest_blockhash(&mut self) -> Result<(Hash, u64), RpcError> { self.retry(|| async { self.client // Confirmed commitments land more reliably than finalized // https://www.helius.dev/blog/how-to-deal-with-blockhash-errors-on-solana#how-to-deal-with-blockhash-errors .get_latest_blockhash_with_commitment(CommitmentConfig::confirmed()) - .map(|response| response.0) .map_err(RpcError::from) }) .await diff --git a/sdk-libs/program-test/src/test_batch_forester.rs b/sdk-libs/program-test/src/test_batch_forester.rs index 95a5444e34..220562c0ab 100644 --- a/sdk-libs/program-test/src/test_batch_forester.rs +++ b/sdk-libs/program-test/src/test_batch_forester.rs @@ -466,7 +466,7 @@ pub async fn create_batched_state_merkle_tree( queue_keypair, cpi_context_keypair, ], - rpc.get_latest_blockhash().await.unwrap(), + rpc.get_latest_blockhash().await?.0, ); rpc.process_transaction(transaction).await } diff --git a/sdk-libs/program-test/src/test_env.rs b/sdk-libs/program-test/src/test_env.rs index 56a6c13205..8a8ba96322 100644 --- a/sdk-libs/program-test/src/test_env.rs +++ b/sdk-libs/program-test/src/test_env.rs @@ -64,7 +64,7 @@ pub async fn setup_test_programs( ) -> ProgramTestContext { let mut program_test = ProgramTest::default(); let sbf_path = std::env::var("SBF_OUT_DIR").unwrap(); - // find path to bin where light cli stores program binaries. + // find a path to bin where light cli stores program binaries. let path = find_light_bin().unwrap(); std::env::set_var("SBF_OUT_DIR", path.to_str().unwrap()); program_test.add_program("light_registry", light_registry::ID, None); @@ -97,7 +97,7 @@ pub async fn setup_test_programs( } fn find_light_bin() -> Option { - // Run the 'which light' command to find the location of 'light' binary + // Run the 'which light' command to find the location of the 'light' binary #[cfg(not(feature = "devenv"))] { @@ -1181,9 +1181,7 @@ pub async fn create_state_merkle_tree_and_queue_account( let merkle_tree_account_create_ix = create_account_instruction( &payer.pubkey(), size, - rpc.get_minimum_balance_for_rent_exemption(size) - .await - .unwrap(), + rpc.get_minimum_balance_for_rent_exemption(size).await?, &account_compression::ID, Some(merkle_tree_keypair), ); @@ -1193,9 +1191,7 @@ pub async fn create_state_merkle_tree_and_queue_account( let nullifier_queue_account_create_ix = create_account_instruction( &payer.pubkey(), size, - rpc.get_minimum_balance_for_rent_exemption(size) - .await - .unwrap(), + rpc.get_minimum_balance_for_rent_exemption(size).await?, &account_compression::ID, Some(nullifier_queue_keypair), ); @@ -1206,8 +1202,7 @@ pub async fn create_state_merkle_tree_and_queue_account( .get_minimum_balance_for_rent_exemption( ProtocolConfig::default().cpi_context_size as usize, ) - .await - .unwrap(); + .await?; let create_cpi_context_instruction = create_account_instruction( &payer.pubkey(), ProtocolConfig::default().cpi_context_size as usize, @@ -1240,7 +1235,7 @@ pub async fn create_state_merkle_tree_and_queue_account( nullifier_queue_keypair, cpi_context_keypair, ], - rpc.get_latest_blockhash().await.unwrap(), + rpc.get_latest_blockhash().await?.0, ) } else { let instruction = create_initialize_merkle_tree_instruction( @@ -1262,7 +1257,7 @@ pub async fn create_state_merkle_tree_and_queue_account( ], Some(&payer.pubkey()), &vec![payer, merkle_tree_keypair, nullifier_queue_keypair], - rpc.get_latest_blockhash().await.unwrap(), + rpc.get_latest_blockhash().await?.0, ) }; @@ -1290,10 +1285,7 @@ pub async fn create_address_merkle_tree_and_queue_account( let account_create_ix = create_account_instruction( &payer.pubkey(), size, - context - .get_minimum_balance_for_rent_exemption(size) - .await - .unwrap(), + context.get_minimum_balance_for_rent_exemption(size).await?, &account_compression::ID, Some(address_queue_keypair), ); @@ -1308,10 +1300,7 @@ pub async fn create_address_merkle_tree_and_queue_account( let mt_account_create_ix = create_account_instruction( &payer.pubkey(), size, - context - .get_minimum_balance_for_rent_exemption(size) - .await - .unwrap(), + context.get_minimum_balance_for_rent_exemption(size).await?, &account_compression::ID, Some(address_merkle_tree_keypair), ); @@ -1348,7 +1337,7 @@ pub async fn create_address_merkle_tree_and_queue_account( ], Some(&payer.pubkey()), &vec![&payer, &address_queue_keypair, &address_merkle_tree_keypair], - context.get_latest_blockhash().await.unwrap(), + context.get_latest_blockhash().await?.0, ); let result = context.process_transaction(transaction.clone()).await; #[allow(clippy::question_mark)] @@ -1371,13 +1360,12 @@ pub async fn register_program_with_registry_program( *group_pda, program_id_keypair.pubkey(), ); - let cpi_authority_pda = light_registry::utils::get_cpi_authority_pda(); + let cpi_authority_pda = get_cpi_authority_pda(); let transfer_instruction = system_instruction::transfer( &governance_authority.pubkey(), &cpi_authority_pda.0, rpc.get_minimum_balance_for_rent_exemption(RegisteredProgram::LEN) - .await - .unwrap(), + .await?, ); rpc.create_and_send_transaction( @@ -1407,8 +1395,7 @@ pub async fn deregister_program_with_registry_program( &governance_authority.pubkey(), &cpi_authority_pda.0, rpc.get_minimum_balance_for_rent_exemption(RegisteredProgram::LEN) - .await - .unwrap(), + .await?, ); rpc.create_and_send_transaction( diff --git a/sdk-libs/program-test/src/test_rpc.rs b/sdk-libs/program-test/src/test_rpc.rs index 8fbc5679ea..2ae7e6eafe 100644 --- a/sdk-libs/program-test/src/test_rpc.rs +++ b/sdk-libs/program-test/src/test_rpc.rs @@ -310,7 +310,7 @@ impl RpcConnection for ProgramTestRpcConnection { &[transfer_instruction], Some(&self.get_payer().pubkey()), &vec![&self.get_payer()], - latest_blockhash, + latest_blockhash.0, ); let sig = *transaction.signatures.first().unwrap(); @@ -331,10 +331,11 @@ impl RpcConnection for ProgramTestRpcConnection { .map_err(RpcError::from) } - async fn get_latest_blockhash(&mut self) -> Result { + async fn get_latest_blockhash(&mut self) -> Result<(Hash, u64), RpcError> { self.context .get_new_latest_blockhash() .await + .map(|hash| (hash, 0)) .map_err(|e| RpcError::from(BanksClientError::from(e))) } diff --git a/xtask/src/new_deployment.rs b/xtask/src/new_deployment.rs index ad48f7296c..e0e4b496fc 100644 --- a/xtask/src/new_deployment.rs +++ b/xtask/src/new_deployment.rs @@ -123,7 +123,7 @@ pub async fn init_new_deployment(options: Options) -> anyhow::Result<()> { &[transfer_instruction], Some(&payer.pubkey()), &vec![&payer], - latest_blockhash, + latest_blockhash.0, ); // Send the transaction From 721ac17347cad612509584392998b3289c8c0ce1 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Fri, 9 May 2025 00:47:56 +0100 Subject: [PATCH 19/24] blockhash --- .../tests/address_merkle_tree_tests.rs | 2 +- .../tests/group_authority_tests.rs | 18 +++++++++--------- .../tests/merkle_tree_tests.rs | 10 +++++----- 3 files changed, 15 insertions(+), 15 deletions(-) diff --git a/program-tests/account-compression-test/tests/address_merkle_tree_tests.rs b/program-tests/account-compression-test/tests/address_merkle_tree_tests.rs index d3ae424094..3f4125688b 100644 --- a/program-tests/account-compression-test/tests/address_merkle_tree_tests.rs +++ b/program-tests/account-compression-test/tests/address_merkle_tree_tests.rs @@ -213,7 +213,7 @@ async fn initialize_address_merkle_tree_and_queue( &[queue_account_create_ix, mt_account_create_ix, instruction], Some(&payer.pubkey()), &vec![&payer, &queue_keypair, &merkle_tree_keypair], - context.get_latest_blockhash().await.unwrap(), + context.get_latest_blockhash().await.unwrap().0, ); context.process_transaction(transaction.clone()).await diff --git a/program-tests/account-compression-test/tests/group_authority_tests.rs b/program-tests/account-compression-test/tests/group_authority_tests.rs index 4a2b27394e..2a22cbefd8 100644 --- a/program-tests/account-compression-test/tests/group_authority_tests.rs +++ b/program-tests/account-compression-test/tests/group_authority_tests.rs @@ -62,7 +62,7 @@ async fn test_create_and_update_group() { data: instruction_data.data(), }; - let latest_blockhash = context.get_latest_blockhash().await.unwrap(); + let latest_blockhash = context.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&context.get_payer().pubkey()), @@ -95,7 +95,7 @@ async fn test_create_and_update_group() { data: update_group_authority_ix.data(), }; - let latest_blockhash = context.get_latest_blockhash().await.unwrap(); + let latest_blockhash = context.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&context.get_payer().pubkey()), @@ -127,7 +127,7 @@ async fn test_create_and_update_group() { data: update_group_authority_ix.data(), }; - let latest_blockhash = context.get_latest_blockhash().await.unwrap(); + let latest_blockhash = context.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&context.get_payer().pubkey()), @@ -166,7 +166,7 @@ async fn test_create_and_update_group() { &[instruction], Some(&updated_keypair.pubkey()), &vec![&updated_keypair, &system_program_id_keypair], - context.get_latest_blockhash().await.unwrap(), + context.get_latest_blockhash().await.unwrap().0, ); context.process_transaction(transaction).await.unwrap(); let registered_program_account = context @@ -201,7 +201,7 @@ async fn test_create_and_update_group() { data: register_program_ix.data(), }; - let latest_blockhash = context.get_latest_blockhash().await.unwrap(); + let latest_blockhash = context.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&context.get_payer().pubkey()), @@ -375,7 +375,7 @@ async fn test_resize_registered_program_pda() { println!("account_data: {:?}", account_data); let mut transaction = Transaction::new_with_payer(&[instruction.clone()], Some(&payer.pubkey())); - let recent_blockhash = context.get_latest_blockhash().await.unwrap(); + let recent_blockhash = context.get_latest_blockhash().await.unwrap().0; transaction.sign(&[&payer], recent_blockhash); context.process_transaction(transaction).await.unwrap(); @@ -401,7 +401,7 @@ async fn test_resize_registered_program_pda() { { let mut transaction = Transaction::new_with_payer(&[instruction.clone()], Some(&payer.pubkey())); - let recent_blockhash = context.get_latest_blockhash().await.unwrap(); + let recent_blockhash = context.get_latest_blockhash().await.unwrap().0; transaction.sign(&[&payer], recent_blockhash); let result = context.process_transaction(transaction).await; assert_rpc_error( @@ -444,7 +444,7 @@ async fn test_resize_registered_program_pda() { }; let mut transaction = Transaction::new_with_payer(&[instruction.clone()], Some(&payer.pubkey())); - let recent_blockhash = context.get_latest_blockhash().await.unwrap(); + let recent_blockhash = context.get_latest_blockhash().await.unwrap().0; transaction.sign(&[&payer], recent_blockhash); let result = context.process_transaction(transaction).await; assert_rpc_error( @@ -484,7 +484,7 @@ async fn test_resize_registered_program_pda() { data: instruction_data.data(), }; let mut transaction = Transaction::new_with_payer(&[instruction], Some(&payer.pubkey())); - let recent_blockhash = context.get_latest_blockhash().await.unwrap(); + let recent_blockhash = context.get_latest_blockhash().await.unwrap().0; transaction.sign(&[&payer], recent_blockhash); let result = context.process_transaction(transaction).await; assert_rpc_error( diff --git a/program-tests/account-compression-test/tests/merkle_tree_tests.rs b/program-tests/account-compression-test/tests/merkle_tree_tests.rs index 7216076ced..3a8b574dac 100644 --- a/program-tests/account-compression-test/tests/merkle_tree_tests.rs +++ b/program-tests/account-compression-test/tests/merkle_tree_tests.rs @@ -1372,7 +1372,7 @@ async fn insert_into_single_nullifier_queue( accounts: [accounts.to_account_metas(Some(true)), remaining_accounts].concat(), data: instruction_data.data(), }; - let latest_blockhash = context.get_latest_blockhash().await.unwrap(); + let latest_blockhash = context.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&fee_payer.pubkey()), @@ -1433,7 +1433,7 @@ async fn insert_into_nullifier_queues( accounts: [accounts.to_account_metas(Some(true)), remaining_accounts].concat(), data: instruction_data.data(), }; - let latest_blockhash = context.get_latest_blockhash().await.unwrap(); + let latest_blockhash = context.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&fee_payer.pubkey()), @@ -1488,7 +1488,7 @@ async fn initialize_state_merkle_tree_and_nullifier_queue( 1, ); - let latest_blockhash = rpc.get_latest_blockhash().await.unwrap(); + let latest_blockhash = rpc.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[ merkle_tree_account_create_ix, @@ -1851,7 +1851,7 @@ pub async fn fail_2_append_leaves_with_invalid_inputs( data: instruction_data.data(), }; - let latest_blockhash = context.get_latest_blockhash().await.unwrap(); + let latest_blockhash = context.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&context.get_payer().pubkey()), @@ -1967,7 +1967,7 @@ pub async fn fail_4_append_leaves_with_invalid_authority( .concat(), data: instruction_data.data(), }; - let latest_blockhash = rpc.get_latest_blockhash().await.unwrap(); + let latest_blockhash = rpc.get_latest_blockhash().await.unwrap().0; let transaction = Transaction::new_signed_with_payer( &[instruction], Some(&invalid_autority.pubkey()), From 1f0718071bae21c7496336c2b69104ddcb479602 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Fri, 9 May 2025 11:05:12 +0100 Subject: [PATCH 20/24] Replace `debug` logs with `trace` and remove unused dependencies --- Cargo.lock | 2 -- forester-utils/Cargo.toml | 2 -- .../src/instructions/state_batch_append.rs | 25 ++++++++------- .../src/instructions/state_batch_nullify.rs | 32 +++++++++++-------- forester/src/epoch_manager.rs | 1 - forester/src/processor/v1/send_transaction.rs | 16 +++++----- forester/src/processor/v1/tx_builder.rs | 6 ++-- forester/src/processor/v2/common.rs | 15 +++++---- 8 files changed, 53 insertions(+), 46 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index cee954138d..5b3d01e5d8 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2250,7 +2250,6 @@ dependencies = [ "anchor-lang", "create-address-test-program", "futures", - "hex", "light-account-checks", "light-batched-merkle-tree", "light-client", @@ -2265,7 +2264,6 @@ dependencies = [ "light-prover-client", "light-registry", "light-system-program-anchor", - "log", "num-bigint 0.4.6", "num-traits", "rand 0.8.5", diff --git a/forester-utils/Cargo.toml b/forester-utils/Cargo.toml index eaaebd4c4e..c2d59da537 100644 --- a/forester-utils/Cargo.toml +++ b/forester-utils/Cargo.toml @@ -49,5 +49,3 @@ rand = { workspace = true } # HTTP client reqwest = { workspace = true } -log = "0.4.26" -hex = "0.4.3" diff --git a/forester-utils/src/instructions/state_batch_append.rs b/forester-utils/src/instructions/state_batch_append.rs index 67ee48be73..b2766ea833 100644 --- a/forester-utils/src/instructions/state_batch_append.rs +++ b/forester-utils/src/instructions/state_batch_append.rs @@ -20,7 +20,7 @@ use light_prover_client::{ }, }; use reqwest::Client; -use tracing::{debug, error, info}; +use tracing::{error, trace}; use crate::{error::ForesterUtilsError, utils::wait_for_indexer}; @@ -31,14 +31,15 @@ pub async fn create_append_batch_ix_data>( merkle_tree_pubkey: Pubkey, output_queue_pubkey: Pubkey, ) -> Result, ForesterUtilsError> { - info!("Creating append batch instruction data"); + trace!("Creating append batch instruction data"); let (merkle_tree_next_index, current_root, root_history) = get_merkle_tree_metadata(rpc, merkle_tree_pubkey).await?; - debug!( + trace!( "merkle_tree_next_index: {:?} current_root: {:?}", - merkle_tree_next_index, current_root + merkle_tree_next_index, + current_root ); // Get output queue metadata and hash chains @@ -46,7 +47,7 @@ pub async fn create_append_batch_ix_data>( get_output_queue_metadata(rpc, output_queue_pubkey).await?; if leaves_hash_chains.is_empty() { - debug!("No hash chains to process"); + trace!("No hash chains to process"); return Ok(Vec::new()); } @@ -68,7 +69,7 @@ pub async fn create_append_batch_ix_data>( ForesterUtilsError::Indexer("Failed to get queue elements".into()) })?; - debug!("Got {} queue elements in total", queue_elements.len()); + trace!("Got {} queue elements in total", queue_elements.len()); if queue_elements.len() != total_elements { return Err(ForesterUtilsError::Indexer(format!( @@ -94,9 +95,11 @@ pub async fn create_append_batch_ix_data>( let end_idx = start_idx + zkp_batch_size as usize; let batch_elements = &queue_elements[start_idx..end_idx]; - debug!( + trace!( "Processing batch {}: index range {}-{}", - batch_idx, start_idx, end_idx + batch_idx, + start_idx, + end_idx ); let old_leaves = batch_elements @@ -147,7 +150,7 @@ pub async fn create_append_batch_ix_data>( for (i, proof_result) in proof_results.into_iter().enumerate() { match proof_result { Ok((proof, new_root)) => { - debug!("Successfully generated proof for batch {}", i); + trace!("Successfully generated proof for batch {}", i); instruction_data_vec.push(InstructionDataBatchAppendInputs { new_root, compressed_proof: proof, @@ -180,7 +183,7 @@ async fn generate_zkp_proof( })?; if response.status().is_success() { - debug!("Received successful response from prover server"); + trace!("Received successful response from prover server"); let body = response.text().await.map_err(|e| { ForesterUtilsError::Prover(format!("Failed to read response body: {}", e)) })?; @@ -259,7 +262,7 @@ async fn get_output_queue_metadata( .push(output_queue.hash_chain_stores[full_batch_index as usize][i as usize]); } - debug!( + trace!( "ZKP batch size: {}, inserted ZKPs: {}, current ZKP index: {}, ready for insertion: {}", zkp_batch_size, num_inserted_zkps, diff --git a/forester-utils/src/instructions/state_batch_nullify.rs b/forester-utils/src/instructions/state_batch_nullify.rs index 6834f368fb..b169267aad 100644 --- a/forester-utils/src/instructions/state_batch_nullify.rs +++ b/forester-utils/src/instructions/state_batch_nullify.rs @@ -16,7 +16,7 @@ use light_prover_client::{ }, }; use reqwest::Client; -use tracing::{debug, error}; +use tracing::{error, trace}; use crate::{error::ForesterUtilsError, utils::wait_for_indexer}; @@ -25,7 +25,7 @@ pub async fn create_nullify_batch_ix_data>( indexer: &mut I, merkle_tree_pubkey: Pubkey, ) -> Result, ForesterUtilsError> { - debug!("create_multiple_nullify_batch_ix_data"); + trace!("create_multiple_nullify_batch_ix_data"); // Get the tree information and find out how many ZKP batches need processing let ( batch_idx, @@ -43,7 +43,7 @@ pub async fn create_nullify_batch_ix_data>( ) .unwrap(); - debug!("queue_batches: {:?}", merkle_tree.queue_batches); + trace!("queue_batches: {:?}", merkle_tree.queue_batches); let batch_idx = merkle_tree.queue_batches.pending_batch_index as usize; let zkp_size = merkle_tree.queue_batches.zkp_batch_size; @@ -71,7 +71,7 @@ pub async fn create_nullify_batch_ix_data>( ) }; - debug!( + trace!( "batch_idx: {}, zkp_batch_size: {}, num_inserted_zkps: {}, num_ready_zkps: {}, leaves_hash_chains: {:?}", batch_idx, zkp_batch_size, num_inserted_zkps, num_ready_zkps, leaves_hash_chains.len() ); @@ -83,14 +83,15 @@ pub async fn create_nullify_batch_ix_data>( wait_for_indexer(rpc, indexer).await?; let current_slot = rpc.get_slot().await.unwrap(); - debug!("current_slot: {}", current_slot); + trace!("current_slot: {}", current_slot); let total_elements = zkp_batch_size as usize * leaves_hash_chains.len(); let offset = num_inserted_zkps * zkp_batch_size as u64; - debug!( + trace!( "Requesting {} total elements with offset {}", - total_elements, offset + total_elements, + offset ); let all_queue_elements = indexer @@ -109,7 +110,7 @@ pub async fn create_nullify_batch_ix_data>( ForesterUtilsError::Indexer("Failed to get queue elements".into()) })?; - debug!("Got {} queue elements in total", all_queue_elements.len()); + trace!("Got {} queue elements in total", all_queue_elements.len()); if all_queue_elements.len() != total_elements { return Err(ForesterUtilsError::Indexer(format!( "Expected {} elements, got {}", @@ -135,9 +136,11 @@ pub async fn create_nullify_batch_ix_data>( let end_idx = start_idx + zkp_batch_size as usize; let batch_elements = &all_queue_elements[start_idx..end_idx]; - debug!( + trace!( "Processing batch {} with offset {}-{}", - batch_offset, start_idx, end_idx + batch_offset, + start_idx, + end_idx ); // Process this batch's data @@ -150,9 +153,12 @@ pub async fn create_nullify_batch_ix_data>( for (i, leaf_info) in batch_elements.iter().enumerate() { let global_leaf_index = start_idx + i; - debug!( + trace!( "Element {}: local index={}, global index={}, reported index={}", - i, i, global_leaf_index, leaf_info.leaf_index + i, + i, + global_leaf_index, + leaf_info.leaf_index ); path_indices.push(leaf_info.leaf_index as u32); @@ -222,7 +228,7 @@ pub async fn create_nullify_batch_ix_data>( new_root, compressed_proof: proof, }); - debug!("Successfully generated proof for batch {}", i); + trace!("Successfully generated proof for batch {}", i); } Err(e) => { error!("Error generating proof for batch {}: {:?}", i, e); diff --git a/forester/src/epoch_manager.rs b/forester/src/epoch_manager.rs index 84e8d5e273..51c5e205d4 100644 --- a/forester/src/epoch_manager.rs +++ b/forester/src/epoch_manager.rs @@ -379,7 +379,6 @@ impl + IndexerType> EpochManager { .await } - #[instrument(level = "debug", skip(self))] async fn process_current_and_previous_epochs(&self, tx: Arc>) -> Result<()> { let (slot, current_epoch) = self.get_current_slot_and_epoch().await?; let current_phases = get_epoch_phases(&self.protocol_config, current_epoch); diff --git a/forester/src/processor/v1/send_transaction.rs b/forester/src/processor/v1/send_transaction.rs index 5ec9f32495..d794e43e57 100644 --- a/forester/src/processor/v1/send_transaction.rs +++ b/forester/src/processor/v1/send_transaction.rs @@ -22,7 +22,7 @@ use solana_sdk::{ transaction::Transaction, }; use tokio::time::Instant; -use tracing::{debug, error, info, trace, warn}; +use tracing::{debug, error, trace, warn}; use crate::{ epoch_manager::WorkItem, @@ -90,7 +90,7 @@ pub async fn send_batched_transactions( .unwrap_or(1) .max(1); - info!(tree = %tree_accounts.merkle_tree, "Starting transaction sending loop. Timeout: {:?}. Max concurrent sends: {}", config.retry_config.timeout, max_concurrent_sends); + trace!(tree = %tree_accounts.merkle_tree, "Starting transaction sending loop. Timeout: {:?}. Max concurrent sends: {}", config.retry_config.timeout, max_concurrent_sends); for work_chunk in data .work_items @@ -101,11 +101,11 @@ pub async fn send_batched_transactions( break; } if Instant::now() >= data.timeout_deadline { - warn!(tree = %tree_accounts.merkle_tree, "Reached global timeout deadline before processing next chunk, stopping."); + trace!(tree = %tree_accounts.merkle_tree, "Reached global timeout deadline before processing next chunk, stopping."); break; } - debug!(tree = %tree_accounts.merkle_tree, "Processing chunk of size {}", work_chunk.len()); + trace!(tree = %tree_accounts.merkle_tree, "Processing chunk of size {}", work_chunk.len()); let build_start_time = Instant::now(); let (transactions_to_send, _) = match transaction_builder @@ -127,7 +127,7 @@ pub async fn send_batched_transactions( break; } }; - debug!(tree = %tree_accounts.merkle_tree, "Built {} transactions in {:?}", transactions_to_send.len(), build_start_time.elapsed()); + trace!(tree = %tree_accounts.merkle_tree, "Built {} transactions in {:?}", transactions_to_send.len(), build_start_time.elapsed()); if Instant::now() >= data.timeout_deadline { warn!(tree = %tree_accounts.merkle_tree, "Reached global timeout deadline after building transactions, stopping."); @@ -151,7 +151,7 @@ pub async fn send_batched_transactions( } let total_sent_successfully = num_sent_transactions.load(Ordering::SeqCst); - debug!(tree = %tree_accounts.merkle_tree, "Transaction sending loop finished. Total transactions sent successfully: {}", total_sent_successfully); + trace!(tree = %tree_accounts.merkle_tree, "Transaction sending loop finished. Total transactions sent successfully: {}", total_sent_successfully); Ok(total_sent_successfully) } @@ -333,7 +333,7 @@ async fn execute_transaction_chunk_sending( } }); - debug!( + trace!( "Executing batch of sends with concurrency limit {}", max_concurrent_sends ); @@ -342,7 +342,7 @@ async fn execute_transaction_chunk_sending( .buffer_unordered(max_concurrent_sends) // buffer_unordered for concurrency .collect::>() .await; - debug!("Finished executing batch in {:?}", exec_start.elapsed()); + trace!("Finished executing batch in {:?}", exec_start.elapsed()); let mut successes = 0; let mut failures = 0; diff --git a/forester/src/processor/v1/tx_builder.rs b/forester/src/processor/v1/tx_builder.rs index 06c05939b8..ed0ad825a3 100644 --- a/forester/src/processor/v1/tx_builder.rs +++ b/forester/src/processor/v1/tx_builder.rs @@ -9,7 +9,7 @@ use solana_sdk::{ transaction::Transaction, }; use tokio::sync::Mutex; -use tracing::{debug, warn}; +use tracing::{trace, warn}; use crate::{ epoch_manager::WorkItem, @@ -85,7 +85,7 @@ impl> TransactionBuilder for EpochManagerTransac .filter(|item| { let hash_str = bs58::encode(&item.queue_item_data.hash).into_string(); if cache.contains(&hash_str) { - debug!("Skipping already processed hash: {}", hash_str); + trace!("Skipping already processed hash: {}", hash_str); false } else { true @@ -100,7 +100,7 @@ impl> TransactionBuilder for EpochManagerTransac drop(cache); if work_items.is_empty() { - debug!("All items in this batch were recently processed, skipping batch"); + trace!("All items in this batch were recently processed, skipping batch"); return Ok((vec![], last_valid_block_height)); } diff --git a/forester/src/processor/v2/common.rs b/forester/src/processor/v2/common.rs index 3dd9690893..68a058d997 100644 --- a/forester/src/processor/v2/common.rs +++ b/forester/src/processor/v2/common.rs @@ -10,7 +10,7 @@ use light_compressed_account::TreeType; use solana_program::pubkey::Pubkey; use solana_sdk::signature::Keypair; use tokio::sync::Mutex; -use tracing::{debug, error, trace, warn}; +use tracing::{error, trace}; use super::{address, error::Result, state, BatchProcessError}; use crate::indexer_type::IndexerType; @@ -89,7 +89,7 @@ impl + IndexerType> BatchProcessor { result } BatchReadyState::NotReady => { - warn!( + trace!( "Batch not ready for processing, tree: {}", self.context.merkle_tree ); @@ -111,9 +111,11 @@ impl + IndexerType> BatchProcessor { false }; - debug!( + trace!( "self.tree_type: {}, input_ready: {}, output_ready: {}", - self.tree_type, input_ready, output_ready + self.tree_type, + input_ready, + output_ready ); if self.tree_type == TreeType::AddressV2 { @@ -220,9 +222,10 @@ impl + IndexerType> BatchProcessor { async fn process_state_nullify(&self) -> Result { let mut rpc = self.context.rpc_pool.get_connection().await?; let (inserted_zkps_count, zkp_batch_size) = self.get_num_inserted_zkps(&mut rpc).await?; - debug!( + trace!( "ZKP batch size: {}, inserted ZKPs count: {}", - zkp_batch_size, inserted_zkps_count + zkp_batch_size, + inserted_zkps_count ); state::perform_nullify(&self.context, &mut rpc).await?; Ok(zkp_batch_size) From 7c6ee0ec27c36b20af007a81924c3495b4d9b132 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Fri, 9 May 2025 13:24:01 +0100 Subject: [PATCH 21/24] Increase sleep duration in utils.rs from 400ms to 500ms --- forester-utils/src/utils.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/forester-utils/src/utils.rs b/forester-utils/src/utils.rs index 5f281069ae..326989eb01 100644 --- a/forester-utils/src/utils.rs +++ b/forester-utils/src/utils.rs @@ -70,7 +70,7 @@ pub async fn wait_for_indexer>( ); tokio::task::yield_now().await; - sleep(std::time::Duration::from_millis(400)).await; + sleep(std::time::Duration::from_millis(500)).await; indexer_slot = indexer.get_indexer_slot(rpc).await.map_err(|e| { error!("failed to get indexer slot from indexer: {:?}", e); ForesterUtilsError::Indexer("Failed to get indexer slot".into()) From 9aa4920192402b716036c70553ee4177b26b3ed5 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Fri, 9 May 2025 16:01:58 +0100 Subject: [PATCH 22/24] Add `#[serial]` attribute to test_transfer_with_transaction_hash --- program-tests/compressed-token-test/tests/test.rs | 1 + 1 file changed, 1 insertion(+) diff --git a/program-tests/compressed-token-test/tests/test.rs b/program-tests/compressed-token-test/tests/test.rs index f460092980..18a2481864 100644 --- a/program-tests/compressed-token-test/tests/test.rs +++ b/program-tests/compressed-token-test/tests/test.rs @@ -5404,6 +5404,7 @@ async fn test_transfer_with_batched_tree() { } } +#[serial] #[tokio::test] async fn test_transfer_with_transaction_hash() { for with_transaction_hash in [true, false] { From 9215f4d8e398c77bc9008d8932e4940b9f688e2c Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Fri, 9 May 2025 19:09:59 +0100 Subject: [PATCH 23/24] spawn prover within batch_compress_with_batched_tree --- program-tests/compressed-token-test/tests/test.rs | 12 ++++++++++-- 1 file changed, 10 insertions(+), 2 deletions(-) diff --git a/program-tests/compressed-token-test/tests/test.rs b/program-tests/compressed-token-test/tests/test.rs index 18a2481864..f7df06f2fe 100644 --- a/program-tests/compressed-token-test/tests/test.rs +++ b/program-tests/compressed-token-test/tests/test.rs @@ -5620,8 +5620,16 @@ async fn batch_compress_with_batched_tree() { .await; let payer = rpc.get_payer().insecure_clone(); let merkle_tree_pubkey = env.batched_output_queue; - let mut test_indexer = - TestIndexer::::init_from_env(&payer, &env, None).await; + let mut test_indexer = TestIndexer::::init_from_env( + &payer, + &env, + Some(ProverConfig { + run_mode: None, + circuits: vec![ProofType::BatchAppendWithProofsTest], + }), + ) + .await; + let sender = Keypair::new(); airdrop_lamports(&mut rpc, &sender.pubkey(), 1_000_000_000) .await From d2106c76b1d5777602736d787defe89c0574d887 Mon Sep 17 00:00:00 2001 From: Sergey Timoshin Date: Fri, 9 May 2025 19:20:14 +0100 Subject: [PATCH 24/24] format --- program-tests/compressed-token-test/tests/test.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/program-tests/compressed-token-test/tests/test.rs b/program-tests/compressed-token-test/tests/test.rs index f7df06f2fe..3748f437c7 100644 --- a/program-tests/compressed-token-test/tests/test.rs +++ b/program-tests/compressed-token-test/tests/test.rs @@ -5620,7 +5620,7 @@ async fn batch_compress_with_batched_tree() { .await; let payer = rpc.get_payer().insecure_clone(); let merkle_tree_pubkey = env.batched_output_queue; - let mut test_indexer = TestIndexer::::init_from_env( + let mut test_indexer = TestIndexer::::init_from_env( &payer, &env, Some(ProverConfig { @@ -5628,7 +5628,7 @@ async fn batch_compress_with_batched_tree() { circuits: vec![ProofType::BatchAppendWithProofsTest], }), ) - .await; + .await; let sender = Keypair::new(); airdrop_lamports(&mut rpc, &sender.pubkey(), 1_000_000_000)