Skip to main content

solana_core/
banking_simulation.rs

1#![cfg(feature = "dev-context-only-utils")]
2use {
3    crate::{
4        banking_stage::{
5            BankingStage, BankingStageHandle, LikeClusterInfo,
6            transaction_scheduler::scheduler_controller::SchedulerConfig,
7            update_bank_forks_and_poh_recorder_for_new_tpu_bank,
8        },
9        banking_trace::{
10            BANKING_TRACE_DIR_DEFAULT_BYTE_LIMIT, BASENAME, BankingTracer, ChannelLabel, Channels,
11            TimedTracedEvent, TracedEvent, TracedSender, TracerThread,
12        },
13        validator::BlockProductionMethod,
14    },
15    agave_banking_stage_ingress_types::{BankingPacketBatch, SchedulerPriorityFloor},
16    agave_votor_messages::migration::MigrationStatus,
17    assert_matches::assert_matches,
18    bincode::deserialize_from,
19    crossbeam_channel::{Sender, bounded, unbounded},
20    itertools::Itertools,
21    log::*,
22    solana_clock::{DEFAULT_MS_PER_SLOT, HOLD_TRANSACTIONS_SLOT_OFFSET, Slot},
23    solana_genesis_config::GenesisConfig,
24    solana_gossip::{cluster_info::ClusterInfo, contact_info::ContactInfoQuery, node::Node},
25    solana_keypair::Keypair,
26    solana_ledger::{
27        blockstore::{Blockstore, PurgeType},
28        leader_schedule_cache::LeaderScheduleCache,
29    },
30    solana_net_utils::{
31        SocketAddrSpace,
32        sockets::{SocketConfiguration, bind_in_range_with_config},
33    },
34    solana_poh::{
35        poh_controller::PohController,
36        poh_recorder::{GRACE_TICKS_FACTOR, MAX_GRACE_SLOTS, PohRecorder},
37        poh_service::{DEFAULT_HASHES_PER_BATCH, DEFAULT_PINNED_CPU_CORE, PohService},
38        record_channels::record_channels,
39        transaction_recorder::TransactionRecorder,
40    },
41    solana_pubkey::Pubkey,
42    solana_runtime::{
43        bank::{Bank, HashOverrides},
44        bank_forks::BankForks,
45        installed_scheduler_pool::BankWithScheduler,
46    },
47    solana_shred_version::compute_shred_version,
48    solana_signer::Signer,
49    solana_turbine::broadcast_stage::{BroadcastStage, BroadcastStageType},
50    std::{
51        collections::BTreeMap,
52        fmt::Display,
53        fs::File,
54        io::{self, BufRead, BufReader},
55        net::{IpAddr, Ipv4Addr},
56        path::PathBuf,
57        sync::{
58            Arc, RwLock,
59            atomic::{AtomicBool, Ordering},
60        },
61        thread::{self, JoinHandle, sleep},
62        time::{Duration, Instant, SystemTime},
63    },
64    thiserror::Error,
65    tokio::sync::mpsc,
66};
67
68/// This creates a simulated environment around `BankingStage` to produce leader's blocks based on
69/// recorded banking trace events (`TimedTracedEvent`).
70///
71/// At a high level, the task of `BankingStage` is to pack transactions into assigned,
72/// fixed-duration, leader blocks. So, there are 3 abstract inputs to simulate: blocks, time, and
73/// transactions.
74///
75/// In the context of simulation, the first two are simple; both are well defined.
76///
77/// For ancestor blocks, we first replay a certain number of blocks immediately up to target
78/// simulation leader's slot with `halt_at_slot` mechanism. Ultimately freezing the ancestor block
79/// with expected and deterministic hashes. This has the added possible benefit of warming caches
80/// that may be used during simulation.
81///
82/// After replay, a minor tweak is applied during simulation: we forcibly override leader's hashes
83/// as the simulated `BankingStage` creates them, using recorded `BlockAndBankHash` events. This is
84/// to provide indistinguishable sysvars to TX execution and identical TX age resolution as the
85/// simulation goes on. Otherwise, the vast majority of TX processing would differ because the
86/// simulated block's hashes would differ than the recorded ones as block composition difference is
87/// inevitable.
88///
89/// As in the real environment, for PoH time we use the `PohRecorder`. This is simply a slot
90/// timer, external to `BankingStage` and thus mostly irrelevant to `BankingStage` performance. For
91/// wall time, we use the first `BankStatus::BlockAndBankHash` and `SystemTime::now()` to define
92/// T=0 for simulation. Then, simulation progress is timed accordingly. For context, this syncing
93/// is necessary because all trace events are recorded in UTC, not relative to poh nor to leader
94/// schedule for simplicity at recording.
95///
96/// Lastly, the last and most complicated input to simulate: transactions.
97///
98/// A closer look of the transaction load profile is below, regardless of internal banking
99/// implementation and simulation:
100///
101/// Due to solana's general tx broadcast strategy of client's submission and optional node
102/// forwarding, many transactions often arrive before the first leader slot begins. Thus, the
103/// initial leader block creation typically starts with rather large number of schedule-able
104/// transactions. Also, note that additional transactions arrive during the 4 leader slot window
105/// (roughly ~1.6 seconds).
106///
107/// Simulation must mimic this load pattern while being agnostic to internal banking impl as much
108/// as possible. For that agnostic objective, `TracedSender`s were introduced into the `SigVerify`
109/// stage and gossip subsystem by `BankingTracer` to trace **all** `BankingPacketBatch`s' exact
110/// payload and _sender_'s timing with `SystemTime::now()` for all `ChannelLabel`s. This deliberate
111/// tracing placement is not to be affected by any `BankingStage`'s internal capacity (if any) nor
112/// by its channel consumption pattern.
113///
114/// BankingSimulator consists of 2 phases chronologically: warm-up and on-the-fly. The 2 phases are
115/// segregated by the aforementioned T=0.
116///
117/// Both phases just send `BankingPacketBatch` in the same fashion, pretending to be
118/// `SigVerifyStage`/gossip from a single thread to busy loop for precise T=N at ~1us granularity.
119///
120/// Warm-up starts at T=-WARMUP_DURATION (~ 13 secs). As soon as warm up is initiated, we invoke
121/// `BankingStage::new_num_threads()` as well to simulate the pre-leader slot's tx-buffering time.
122pub struct BankingSimulator {
123    banking_trace_events: BankingTraceEvents,
124    first_simulated_slot: Slot,
125}
126
127#[derive(Error, Debug)]
128pub enum SimulateError {
129    #[error("IO Error: {0}")]
130    IoError(#[from] io::Error),
131
132    #[error("Deserialization Error: {0}")]
133    DeserializeError(#[from] bincode::Error),
134}
135
136// Defined to be enough to cover the holding phase prior to leader slots with some idling (+5 secs)
137const WARMUP_DURATION: Duration =
138    Duration::from_millis(HOLD_TRANSACTIONS_SLOT_OFFSET * DEFAULT_MS_PER_SLOT + 5000);
139
140/// BTreeMap is intentional because events could be unordered slightly due to tracing jitter.
141type PacketBatchesByTime = BTreeMap<SystemTime, (ChannelLabel, BankingPacketBatch)>;
142
143type FreezeTimeBySlot = BTreeMap<Slot, SystemTime>;
144
145type TimedBatchesToSend = Vec<(
146    (Duration, (ChannelLabel, BankingPacketBatch)),
147    (usize, usize),
148)>;
149
150type EventSenderThread = JoinHandle<(TracedSender, TracedSender, TracedSender)>;
151
152#[derive(Default)]
153pub struct BankingTraceEvents {
154    packet_batches_by_time: PacketBatchesByTime,
155    freeze_time_by_slot: FreezeTimeBySlot,
156    hash_overrides: HashOverrides,
157}
158
159impl BankingTraceEvents {
160    fn read_event_file(
161        event_file_path: &PathBuf,
162        mut callback: impl FnMut(TimedTracedEvent),
163    ) -> Result<(), SimulateError> {
164        let mut reader = BufReader::new(File::open(event_file_path)?);
165
166        // EOF is reached at a correct deserialization boundary or just the file is just empty.
167        // We want to look-ahead the buf, so NOT calling reader.consume(..) is correct.
168        while !reader.fill_buf()?.is_empty() {
169            callback(deserialize_from(&mut reader)?);
170        }
171
172        Ok(())
173    }
174
175    pub fn load(event_file_paths: &[PathBuf]) -> Result<Self, SimulateError> {
176        let mut event_count = 0;
177        let mut events = Self::default();
178        for event_file_path in event_file_paths {
179            let old_event_count = event_count;
180            let read_result = Self::read_event_file(event_file_path, |event| {
181                event_count += 1;
182                events.load_event(event);
183            });
184            info!(
185                "Read {} events from {:?}",
186                event_count - old_event_count,
187                event_file_path,
188            );
189
190            if matches!(
191                read_result,
192                Err(SimulateError::DeserializeError(ref deser_err))
193                    if matches!(
194                        &**deser_err,
195                        bincode::ErrorKind::Io(io_err)
196                            if io_err.kind() == std::io::ErrorKind::UnexpectedEof
197                    )
198            ) {
199                // Silence errors here as this can happen under normal operation...
200                warn!(
201                    "Reading {event_file_path:?} failed {read_result:?} due to file corruption or \
202                     unclean validator shutdown",
203                );
204            } else {
205                read_result?
206            }
207        }
208
209        Ok(events)
210    }
211
212    fn load_event(&mut self, TimedTracedEvent(event_time, event): TimedTracedEvent) {
213        match event {
214            TracedEvent::PacketBatch(label, batch) => {
215                // Deserialized PacketBatches will mostly be ordered by event_time, but this
216                // isn't guaranteed when traced, because time are measured by multiple _sender_
217                // threads without synchronization among them to avoid overhead.
218                //
219                // Also, there's a possibility of system clock change. In this case,
220                // the simulation is meaningless, though...
221                //
222                // Somewhat naively assume that event_times (nanosecond resolution) won't
223                // collide.
224                let is_new = self
225                    .packet_batches_by_time
226                    .insert(event_time, (label, batch))
227                    .is_none();
228                assert!(is_new);
229            }
230            TracedEvent::BlockAndBankHash(slot, blockhash, bank_hash) => {
231                let is_new = self.freeze_time_by_slot.insert(slot, event_time).is_none();
232                self.hash_overrides.add_override(slot, blockhash, bank_hash);
233                assert!(is_new);
234            }
235        }
236    }
237
238    pub fn hash_overrides(&self) -> &HashOverrides {
239        &self.hash_overrides
240    }
241}
242
243struct DummyClusterInfo {
244    // Artificially wrap Pubkey with RwLock to induce lock contention if any to mimic the real
245    // ClusterInfo
246    id: RwLock<Pubkey>,
247}
248
249impl LikeClusterInfo for Arc<DummyClusterInfo> {
250    fn id(&self) -> Pubkey {
251        *self.id.read().unwrap()
252    }
253
254    fn lookup_contact_info<R>(&self, _: &Pubkey, _: impl ContactInfoQuery<R>) -> Option<R> {
255        None
256    }
257}
258
259struct SimulatorLoopLogger {
260    simulated_leader: Pubkey,
261    freeze_time_by_slot: FreezeTimeBySlot,
262    base_event_time: SystemTime,
263    base_simulation_time: SystemTime,
264}
265
266impl SimulatorLoopLogger {
267    fn bank_cost(bank: &Bank) -> u64 {
268        bank.read_cost_tracker().map(|t| t.block_cost()).unwrap()
269    }
270
271    fn log_frozen_bank_cost(&self, bank: &Bank, bank_elapsed: Duration) {
272        info!(
273            "simulated bank slot+delta: {}+{}ms cost: {} fees: {:?} txs: {} (frozen)",
274            bank.slot(),
275            bank_elapsed.as_millis(),
276            Self::bank_cost(bank),
277            bank.get_collector_fee_details(),
278            bank.executed_transaction_count(),
279        );
280    }
281
282    fn log_ongoing_bank_cost(&self, bank: &Bank, bank_elapsed: Duration) {
283        info!(
284            "simulated bank slot+delta: {}+{}ms cost: {} fees: {:?} txs: {} (ongoing)",
285            bank.slot(),
286            bank_elapsed.as_millis(),
287            Self::bank_cost(bank),
288            bank.get_collector_fee_details(),
289            bank.executed_transaction_count(),
290        );
291    }
292
293    fn log_jitter(&self, bank: &Bank) {
294        let old_slot = bank.slot();
295        if let Some(event_time) = self.freeze_time_by_slot.get(&old_slot)
296            && log_enabled!(log::Level::Info)
297        {
298            let current_simulation_time = SystemTime::now();
299            let elapsed_simulation_time = current_simulation_time
300                .duration_since(self.base_simulation_time)
301                .unwrap();
302            let elapsed_event_time = event_time.duration_since(self.base_event_time).unwrap();
303            info!(
304                "jitter(parent_slot: {}): {}{:?} (sim: {:?} event: {:?})",
305                old_slot,
306                if elapsed_simulation_time > elapsed_event_time {
307                    "+"
308                } else {
309                    "-"
310                },
311                elapsed_simulation_time.abs_diff(elapsed_event_time),
312                elapsed_simulation_time,
313                elapsed_event_time,
314            );
315        }
316    }
317
318    fn on_new_leader(
319        &self,
320        bank: &Bank,
321        bank_elapsed: Duration,
322        new_slot: Slot,
323        new_leader: Pubkey,
324    ) {
325        self.log_frozen_bank_cost(bank, bank_elapsed);
326        info!(
327            "{} isn't leader anymore at slot {}; new leader: {}",
328            self.simulated_leader, new_slot, new_leader
329        );
330    }
331}
332
333struct SenderLoop {
334    parent_slot: Slot,
335    first_simulated_slot: Slot,
336    non_vote_sender: TracedSender,
337    tpu_vote_sender: TracedSender,
338    gossip_vote_sender: TracedSender,
339    exit: Arc<AtomicBool>,
340    raw_base_event_time: SystemTime,
341    total_batch_count: usize,
342    timed_batches_to_send: TimedBatchesToSend,
343}
344
345impl SenderLoop {
346    fn log_starting(&self) {
347        info!(
348            "simulating events: {} (out of {}), starting at slot {} (based on {} from traced \
349             event slot: {}) (warmup: -{:?})",
350            self.timed_batches_to_send.len(),
351            self.total_batch_count,
352            self.first_simulated_slot,
353            SenderLoopLogger::format_as_timestamp(self.raw_base_event_time),
354            self.parent_slot,
355            WARMUP_DURATION,
356        );
357    }
358
359    fn spawn(self, base_simulation_time: SystemTime) -> Result<EventSenderThread, SimulateError> {
360        let handle = thread::Builder::new()
361            .name("solSimSender".into())
362            .spawn(move || self.start(base_simulation_time))?;
363        Ok(handle)
364    }
365
366    fn start(
367        mut self,
368        base_simulation_time: SystemTime,
369    ) -> (TracedSender, TracedSender, TracedSender) {
370        let mut logger = SenderLoopLogger::new(
371            &self.non_vote_sender,
372            &self.tpu_vote_sender,
373            &self.gossip_vote_sender,
374        );
375        let mut simulation_duration = Duration::default();
376        for ((required_duration, (label, batches_with_stats)), (batch_count, tx_count)) in
377            self.timed_batches_to_send.drain(..)
378        {
379            // Busy loop for most accurate sending timings
380            while simulation_duration < required_duration {
381                let current_simulation_time = SystemTime::now();
382                simulation_duration = current_simulation_time
383                    .duration_since(base_simulation_time)
384                    .unwrap();
385            }
386
387            let sender = match label {
388                ChannelLabel::NonVote => &self.non_vote_sender,
389                ChannelLabel::TpuVote => &self.tpu_vote_sender,
390                ChannelLabel::GossipVote => &self.gossip_vote_sender,
391                ChannelLabel::Dummy => unreachable!(),
392            };
393            sender.send(batches_with_stats).unwrap();
394
395            logger.on_sending_batches(&simulation_duration, label, batch_count, tx_count);
396            if self.exit.load(Ordering::Relaxed) {
397                break;
398            }
399        }
400        logger.on_terminating();
401        drop(self.timed_batches_to_send);
402        // hold these senders in join_handle to control banking stage termination!
403        (
404            self.non_vote_sender,
405            self.tpu_vote_sender,
406            self.gossip_vote_sender,
407        )
408    }
409}
410
411struct SimulatorLoop {
412    bank: BankWithScheduler,
413    parent_slot: Slot,
414    first_simulated_slot: Slot,
415    freeze_time_by_slot: FreezeTimeBySlot,
416    base_event_time: SystemTime,
417    poh_recorder: Arc<RwLock<PohRecorder>>,
418    poh_controller: PohController,
419    simulated_leader: Pubkey,
420    bank_forks: Arc<RwLock<BankForks>>,
421    blockstore: Arc<Blockstore>,
422    leader_schedule_cache: Arc<LeaderScheduleCache>,
423    retransmit_slots_sender: Sender<Slot>,
424    retracer: Arc<BankingTracer>,
425}
426
427impl SimulatorLoop {
428    fn enter(
429        self,
430        base_simulation_time: SystemTime,
431        sender_thread: EventSenderThread,
432    ) -> (EventSenderThread, Sender<Slot>) {
433        sleep(WARMUP_DURATION);
434        info!("warmup done!");
435        self.start(base_simulation_time, sender_thread)
436    }
437
438    fn start(
439        mut self,
440        base_simulation_time: SystemTime,
441        sender_thread: EventSenderThread,
442    ) -> (EventSenderThread, Sender<Slot>) {
443        let logger = SimulatorLoopLogger {
444            simulated_leader: self.simulated_leader,
445            base_event_time: self.base_event_time,
446            base_simulation_time,
447            freeze_time_by_slot: self.freeze_time_by_slot,
448        };
449        let (mut bank, mut bank_created) = (self.bank, Instant::now());
450        loop {
451            if self.poh_recorder.read().unwrap().bank().is_none() {
452                let next_leader_slot = self.leader_schedule_cache.next_leader_slot(
453                    &self.simulated_leader,
454                    bank.slot(),
455                    &bank,
456                    Some(&self.blockstore),
457                    GRACE_TICKS_FACTOR * MAX_GRACE_SLOTS,
458                );
459                debug!("{next_leader_slot:?}");
460                self.poh_controller
461                    .reset_sync(bank.clone_without_scheduler(), next_leader_slot)
462                    .unwrap();
463                info!("Bank::new_from_parent()!");
464
465                logger.log_jitter(&bank);
466                if let Some((result, _execute_timings)) = bank.wait_for_completed_scheduler() {
467                    assert_matches!(result, Ok(()));
468                }
469                bank.freeze();
470                let new_slot = if bank.slot() == self.parent_slot {
471                    info!("initial leader block!");
472                    self.first_simulated_slot
473                } else {
474                    info!("next leader block!");
475                    bank.slot() + 1
476                };
477                let new_leader = self
478                    .leader_schedule_cache
479                    .slot_leader_at(new_slot, None)
480                    .unwrap();
481                if new_leader.id != self.simulated_leader {
482                    logger.on_new_leader(&bank, bank_created.elapsed(), new_slot, new_leader.id);
483                    break;
484                } else if sender_thread.is_finished() {
485                    warn!("sender thread existed maybe due to completion of sending traced events");
486                    break;
487                } else {
488                    info!("new leader bank slot: {new_slot}");
489                }
490                let new_bank =
491                    Bank::new_from_parent(bank.clone_without_scheduler(), new_leader, new_slot);
492                // make sure parent is frozen for finalized hashes via the above
493                // new()-ing of its child bank
494                self.retracer
495                    .hash_event(bank.slot(), &bank.last_blockhash(), &bank.hash());
496                if *bank.leader_id() == self.simulated_leader {
497                    logger.log_frozen_bank_cost(&bank, bank_created.elapsed());
498                }
499                self.retransmit_slots_sender.send(bank.slot()).unwrap();
500                update_bank_forks_and_poh_recorder_for_new_tpu_bank(
501                    &self.bank_forks,
502                    &mut self.poh_controller,
503                    new_bank,
504                );
505                // Wait for the controller message to be processed.
506                // This loop assumes that
507                // `update_bank_forks_and_poh_recorder_for_new_tpu_bank`
508                // takes immediate effect in PohRecorder's working bank.
509                while self.poh_controller.has_pending_message() {}
510
511                (bank, bank_created) = (
512                    self.bank_forks
513                        .read()
514                        .unwrap()
515                        .working_bank_with_scheduler(),
516                    Instant::now(),
517                );
518                logger.log_ongoing_bank_cost(&bank, bank_created.elapsed());
519            } else {
520                logger.log_ongoing_bank_cost(&bank, bank_created.elapsed());
521            }
522
523            sleep(Duration::from_millis(10));
524        }
525
526        (sender_thread, self.retransmit_slots_sender)
527    }
528}
529
530struct SimulatorThreads {
531    poh_service: PohService,
532    banking_stage: BankingStageHandle,
533    broadcast_stage: BroadcastStage,
534    retracer_thread: TracerThread,
535    exit: Arc<AtomicBool>,
536}
537
538impl SimulatorThreads {
539    fn finish(self, sender_thread: EventSenderThread, retransmit_slots_sender: Sender<Slot>) {
540        info!("Sleeping a bit before signaling exit");
541        sleep(Duration::from_millis(100));
542        self.exit.store(true, Ordering::Relaxed);
543
544        // The order is important. Consuming sender_thread by joining will drop some channels. That
545        // triggers termination of banking_stage, in turn retracer thread will be terminated.
546        sender_thread.join().unwrap();
547        self.banking_stage.join().unwrap();
548        self.poh_service.join().unwrap();
549        if let Some(retracer_thread) = self.retracer_thread {
550            retracer_thread.join().unwrap().unwrap();
551        }
552
553        info!("Joining broadcast stage...");
554        drop(retransmit_slots_sender);
555        self.broadcast_stage.join().unwrap();
556    }
557}
558
559struct SenderLoopLogger<'a> {
560    non_vote_sender: &'a TracedSender,
561    tpu_vote_sender: &'a TracedSender,
562    gossip_vote_sender: &'a TracedSender,
563    last_log_duration: Duration,
564    last_tx_count: usize,
565    last_non_vote_batch_count: usize,
566    last_tpu_vote_tx_count: usize,
567    last_gossip_vote_tx_count: usize,
568    non_vote_batch_count: usize,
569    non_vote_tx_count: usize,
570    tpu_vote_batch_count: usize,
571    tpu_vote_tx_count: usize,
572    gossip_vote_batch_count: usize,
573    gossip_vote_tx_count: usize,
574}
575
576impl<'a> SenderLoopLogger<'a> {
577    fn new(
578        non_vote_sender: &'a TracedSender,
579        tpu_vote_sender: &'a TracedSender,
580        gossip_vote_sender: &'a TracedSender,
581    ) -> Self {
582        Self {
583            non_vote_sender,
584            tpu_vote_sender,
585            gossip_vote_sender,
586            last_log_duration: Duration::default(),
587            last_tx_count: 0,
588            last_non_vote_batch_count: 0,
589            last_tpu_vote_tx_count: 0,
590            last_gossip_vote_tx_count: 0,
591            non_vote_batch_count: 0,
592            non_vote_tx_count: 0,
593            tpu_vote_batch_count: 0,
594            tpu_vote_tx_count: 0,
595            gossip_vote_batch_count: 0,
596            gossip_vote_tx_count: 0,
597        }
598    }
599
600    fn on_sending_batches(
601        &mut self,
602        &simulation_duration: &Duration,
603        label: ChannelLabel,
604        batch_count: usize,
605        tx_count: usize,
606    ) {
607        debug!("sent {label:?} {batch_count} batches ({tx_count} txes)");
608
609        use ChannelLabel::*;
610        let (total_batch_count, total_tx_count) = match label {
611            NonVote => (&mut self.non_vote_batch_count, &mut self.non_vote_tx_count),
612            TpuVote => (&mut self.tpu_vote_batch_count, &mut self.tpu_vote_tx_count),
613            GossipVote => (
614                &mut self.gossip_vote_batch_count,
615                &mut self.gossip_vote_tx_count,
616            ),
617            Dummy => unreachable!(),
618        };
619        *total_batch_count += batch_count;
620        *total_tx_count += tx_count;
621
622        let log_interval = simulation_duration - self.last_log_duration;
623        if log_interval > Duration::from_millis(100) {
624            let current_tx_count =
625                self.non_vote_tx_count + self.tpu_vote_tx_count + self.gossip_vote_tx_count;
626            let duration = log_interval.as_secs_f64();
627            let tps = (current_tx_count - self.last_tx_count) as f64 / duration;
628            let non_vote_tps =
629                (self.non_vote_tx_count - self.last_non_vote_batch_count) as f64 / duration;
630            let tpu_vote_tps =
631                (self.tpu_vote_tx_count - self.last_tpu_vote_tx_count) as f64 / duration;
632            let gossip_vote_tps =
633                (self.gossip_vote_tx_count - self.last_gossip_vote_tx_count) as f64 / duration;
634            info!(
635                "senders(non-,tpu-,gossip-vote): tps: {:.0} (={:.0}+{:.0}+{:.0}) over {:?} \
636                 not-recved: ({}+{}+{})",
637                tps,
638                non_vote_tps,
639                tpu_vote_tps,
640                gossip_vote_tps,
641                log_interval,
642                self.non_vote_sender.len(),
643                self.tpu_vote_sender.len(),
644                self.gossip_vote_sender.len(),
645            );
646            self.last_log_duration = simulation_duration;
647            self.last_tx_count = current_tx_count;
648            (
649                self.last_non_vote_batch_count,
650                self.last_tpu_vote_tx_count,
651                self.last_gossip_vote_tx_count,
652            ) = (
653                self.non_vote_tx_count,
654                self.tpu_vote_tx_count,
655                self.gossip_vote_batch_count,
656            );
657        }
658    }
659
660    fn on_terminating(self) {
661        info!(
662            "terminating to send...: non_vote: {} ({}), tpu_vote: {} ({}), gossip_vote: {} ({})",
663            self.non_vote_batch_count,
664            self.non_vote_tx_count,
665            self.tpu_vote_batch_count,
666            self.tpu_vote_tx_count,
667            self.gossip_vote_batch_count,
668            self.gossip_vote_tx_count,
669        );
670    }
671
672    fn format_as_timestamp(time: SystemTime) -> impl Display + use<> {
673        let time: chrono::DateTime<chrono::Utc> = time.into();
674        time.format("%Y-%m-%d %H:%M:%S.%f")
675    }
676}
677
678impl BankingSimulator {
679    pub fn new(banking_trace_events: BankingTraceEvents, first_simulated_slot: Slot) -> Self {
680        Self {
681            banking_trace_events,
682            first_simulated_slot,
683        }
684    }
685
686    pub fn parent_slot(&self) -> Option<Slot> {
687        self.banking_trace_events
688            .freeze_time_by_slot
689            .range(..self.first_simulated_slot)
690            .last()
691            .map(|(slot, _time)| slot)
692            .copied()
693    }
694
695    fn prepare_simulation(
696        self,
697        genesis_config: GenesisConfig,
698        bank_forks: Arc<RwLock<BankForks>>,
699        blockstore: Arc<Blockstore>,
700        block_production_method: BlockProductionMethod,
701    ) -> (SenderLoop, SimulatorLoop, SimulatorThreads) {
702        let parent_slot = self.parent_slot().unwrap();
703        let mut packet_batches_by_time = self.banking_trace_events.packet_batches_by_time;
704        let freeze_time_by_slot = self.banking_trace_events.freeze_time_by_slot;
705        let bank = bank_forks.read().unwrap().working_bank_with_scheduler();
706
707        let leader_schedule_cache = Arc::new(LeaderScheduleCache::new_from_bank(&bank));
708        assert_eq!(parent_slot, bank.slot());
709
710        let simulated_leader = leader_schedule_cache
711            .slot_leader_at(self.first_simulated_slot, None)
712            .unwrap()
713            .id;
714        info!(
715            "Simulated leader and slot: {}, {}",
716            simulated_leader, self.first_simulated_slot,
717        );
718
719        let exit = Arc::new(AtomicBool::default());
720
721        if let Some(end_slot) = blockstore
722            .slot_meta_iterator(self.first_simulated_slot)
723            .unwrap()
724            .map(|(s, _)| s)
725            .last()
726        {
727            info!("purging slots {}, {}", self.first_simulated_slot, end_slot);
728            blockstore.purge_from_next_slots(self.first_simulated_slot, end_slot);
729            blockstore
730                .purge_slots(self.first_simulated_slot, end_slot, PurgeType::Exact)
731                .unwrap();
732            info!("done: purging");
733        } else {
734            info!("skipping purging...");
735        }
736
737        info!("Poh is starting!");
738
739        let (poh_recorder, entry_receiver) = PohRecorder::new_with_clear_signal(
740            bank.tick_height(),
741            bank.last_blockhash(),
742            bank.clone(),
743            None,
744            bank.ticks_per_slot(),
745            false,
746            blockstore.clone(),
747            blockstore.get_new_shred_signal(0),
748            &leader_schedule_cache,
749            &genesis_config.poh_config,
750            exit.clone(),
751        );
752        let poh_recorder = Arc::new(RwLock::new(poh_recorder));
753        let (record_sender, record_receiver) = record_channels(false);
754        let transaction_recorder = TransactionRecorder::new(record_sender);
755        let (poh_controller, poh_service_message_receiver) = PohController::new();
756        let (record_receiver_sender, _record_receiver_receiver) = bounded(1);
757        let poh_service = PohService::new(
758            poh_recorder.clone(),
759            &genesis_config.poh_config,
760            exit.clone(),
761            bank.ticks_per_slot(),
762            DEFAULT_PINNED_CPU_CORE,
763            DEFAULT_HASHES_PER_BATCH,
764            record_receiver,
765            poh_service_message_receiver,
766            Arc::new(MigrationStatus::default()),
767            record_receiver_sender,
768        );
769
770        // Enable BankingTracer to approximate the real environment as close as possible because
771        // it's not expected to disable BankingTracer on production environments.
772        //
773        // It's not likely for it to affect the banking stage performance noticeably. So, make sure
774        // that assumption is held here. That said, it incurs additional channel sending,
775        // SystemTime::now() and buffered seq IO, and indirectly functions as a background dropper
776        // of `BankingPacketBatch`.
777        //
778        // Lastly, the actual retraced events can be used to evaluate simulation timing accuracy in
779        // the future.
780        let (retracer, retracer_thread) = BankingTracer::new(Some((
781            &blockstore.banking_retracer_path(),
782            exit.clone(),
783            BANKING_TRACE_DIR_DEFAULT_BYTE_LIMIT,
784        )))
785        .unwrap();
786        assert!(retracer.is_enabled());
787        info!("Enabled banking retracer (dir_byte_limit: {BANKING_TRACE_DIR_DEFAULT_BYTE_LIMIT})",);
788
789        let num_workers = BankingStage::default_num_workers();
790        let banking_tracer_channels = retracer.create_channels();
791        let Channels {
792            non_vote_sender,
793            non_vote_receiver,
794            tpu_vote_sender,
795            tpu_vote_receiver,
796            gossip_vote_sender,
797            gossip_vote_receiver,
798        } = banking_tracer_channels;
799
800        let (replay_vote_sender, _replay_vote_receiver) = unbounded();
801        let (retransmit_slots_sender, retransmit_slots_receiver) = unbounded();
802        let (completed_block_sender, _completed_block_receiver) = unbounded();
803        let shred_version = compute_shred_version(
804            &genesis_config.hash(),
805            Some(&bank_forks.read().unwrap().root_bank().hard_forks()),
806        );
807
808        // Create a completely-dummy ClusterInfo for the broadcast stage.
809        // We only need it to write shreds into the blockstore and it seems given ClusterInfo is
810        // irrelevant for the necessary minimum work for this simulation.
811        let random_keypair = Arc::new(Keypair::new());
812        let cluster_info_for_broadcast = Arc::new(ClusterInfo::new(
813            Node::new_localhost_with_pubkey(&random_keypair.pubkey()).info,
814            random_keypair,
815            SocketAddrSpace::Unspecified,
816        ));
817        // Broadcast stage is needed to save the simulated blocks for post-run analysis by
818        // inserting produced shreds into the blockstore.
819        let (_, socket) = bind_in_range_with_config(
820            IpAddr::V4(Ipv4Addr::LOCALHOST),
821            (1024, u16::MAX),
822            SocketConfiguration::default(),
823        )
824        .expect("should bind");
825        let broadcast_stage = BroadcastStageType::Standard.new_broadcast_stage(
826            vec![socket],
827            cluster_info_for_broadcast,
828            entry_receiver,
829            retransmit_slots_receiver,
830            exit.clone(),
831            blockstore.clone(),
832            bank_forks.clone(),
833            leader_schedule_cache.clone(),
834            shred_version,
835            None,
836            completed_block_sender,
837        );
838
839        info!("Start banking stage!...");
840        let banking_stage = BankingStage::new_num_threads(
841            block_production_method,
842            poh_recorder.clone(),
843            transaction_recorder,
844            non_vote_receiver,
845            tpu_vote_receiver,
846            gossip_vote_receiver,
847            mpsc::channel(1).1,
848            num_workers,
849            SchedulerConfig::default(),
850            None,
851            replay_vote_sender,
852            None,
853            bank_forks.clone(),
854            None,
855            Arc::default(),
856            Arc::new(SchedulerPriorityFloor::default()),
857        );
858
859        let (&_slot, &raw_base_event_time) = freeze_time_by_slot
860            .range(parent_slot..)
861            .next()
862            .expect("timed hashes");
863        let base_event_time = raw_base_event_time - WARMUP_DURATION;
864
865        let total_batch_count = packet_batches_by_time.len();
866        let timed_batches_to_send = packet_batches_by_time.split_off(&base_event_time);
867        let batch_and_tx_counts = timed_batches_to_send
868            .values()
869            .map(|(_label, batches)| {
870                (
871                    batches.len(),
872                    batches.iter().map(|batch| batch.len()).sum::<usize>(),
873                )
874            })
875            .collect::<Vec<_>>();
876        // Convert to a large plain old Vec and drain on it, finally dropping it outside
877        // the simulation loop to avoid jitter due to interleaved deallocs of BTreeMap.
878        let timed_batches_to_send = timed_batches_to_send
879            .into_iter()
880            .map(|(event_time, batches)| {
881                (event_time.duration_since(base_event_time).unwrap(), batches)
882            })
883            .zip_eq(batch_and_tx_counts)
884            .collect::<Vec<_>>();
885
886        let sender_loop = SenderLoop {
887            parent_slot,
888            first_simulated_slot: self.first_simulated_slot,
889            non_vote_sender,
890            tpu_vote_sender,
891            gossip_vote_sender,
892            exit: exit.clone(),
893            raw_base_event_time,
894            total_batch_count,
895            timed_batches_to_send,
896        };
897
898        let simulator_loop = SimulatorLoop {
899            bank,
900            parent_slot,
901            first_simulated_slot: self.first_simulated_slot,
902            freeze_time_by_slot,
903            base_event_time,
904            poh_recorder,
905            poh_controller,
906            simulated_leader,
907            bank_forks,
908            blockstore,
909            leader_schedule_cache,
910            retransmit_slots_sender,
911            retracer,
912        };
913
914        let simulator_threads = SimulatorThreads {
915            poh_service,
916            banking_stage,
917            broadcast_stage,
918            retracer_thread,
919            exit,
920        };
921
922        (sender_loop, simulator_loop, simulator_threads)
923    }
924
925    pub fn start(
926        self,
927        genesis_config: GenesisConfig,
928        bank_forks: Arc<RwLock<BankForks>>,
929        blockstore: Arc<Blockstore>,
930        block_production_method: BlockProductionMethod,
931    ) -> Result<(), SimulateError> {
932        let (sender_loop, simulator_loop, simulator_threads) = self.prepare_simulation(
933            genesis_config,
934            bank_forks,
935            blockstore,
936            block_production_method,
937        );
938
939        sender_loop.log_starting();
940        let base_simulation_time = SystemTime::now();
941        // Spawning and entering these two loops must be done at the same time as they're timed.
942        // So, all the mundane setup must be done in advance.
943        let sender_thread = sender_loop.spawn(base_simulation_time)?;
944        let (sender_thread, retransmit_slots_sender) =
945            simulator_loop.enter(base_simulation_time, sender_thread);
946
947        simulator_threads.finish(sender_thread, retransmit_slots_sender);
948
949        Ok(())
950    }
951
952    pub fn event_file_name(index: usize) -> String {
953        if index == 0 {
954            BASENAME.to_string()
955        } else {
956            format!("{BASENAME}.{index}")
957        }
958    }
959}