1use std::{
5 convert::TryFrom,
6 num::{NonZeroU64, NonZeroUsize},
7 sync::{
8 Arc, LazyLock,
9 atomic::{AtomicU64, Ordering},
10 },
11 time::{Duration, Instant},
12};
13
14use crate::{
15 blocks::{FullTipset, Tipset, TipsetKey, TipsetLike},
16 db::DbImpl,
17 libp2p::{
18 NetworkMessage, PeerId, PeerManager,
19 chain_exchange::{
20 ChainExchangeRequest, ChainExchangeResponse, HEADERS, MESSAGES, TipsetBundle,
21 },
22 hello::{HelloRequest, HelloResponse},
23 rpc::RequestResponseError,
24 },
25 prelude::*,
26 utils::{
27 misc::{AdaptiveValueProvider, ExponentialAdaptiveValueProvider},
28 stats::Stats,
29 },
30};
31use anyhow::Context as _;
32use nonzero_ext::nonzero;
33use parking_lot::Mutex;
34use std::future::Future;
35use tokio::sync::Semaphore;
36use tokio::task::JoinSet;
37use tracing::{debug, trace};
38
39static CHAIN_EXCHANGE_TIMEOUT_MILLIS: LazyLock<ExponentialAdaptiveValueProvider<u64>> =
43 LazyLock::new(|| ExponentialAdaptiveValueProvider::new(5000, 2000, 60000, false));
44
45static MAX_CONCURRENT_CHAIN_EXCHANGE_REQUESTS: LazyLock<NonZeroUsize> = LazyLock::new(|| {
48 std::env::var("FOREST_MAX_CONCURRENT_CHAIN_EXCHANGE_REQUESTS")
49 .ok()
50 .and_then(|i| {
51 i.parse().ok().inspect(|i| {
52 tracing::info!("max concurrent chain exchange requests set to {i} from `FOREST_MAX_CONCURRENT_CHAIN_EXCHANGE_REQUESTS`");
53 })
54 }).unwrap_or(nonzero!(3_usize))
55});
56
57#[derive(derive_more::Constructor)]
61pub struct SyncNetworkContext {
62 network_send: flume::Sender<NetworkMessage>,
64 peer_manager: Arc<PeerManager>,
67 db: DbImpl,
68}
69
70impl ShallowClone for SyncNetworkContext {
71 fn shallow_clone(&self) -> Self {
72 Self {
73 network_send: self.network_send.clone(),
74 peer_manager: self.peer_manager.shallow_clone(),
75 db: self.db.shallow_clone(),
76 }
77 }
78}
79
80struct RaceBatch<T> {
83 tasks: JoinSet<anyhow::Result<T>>,
84 semaphore: Arc<Semaphore>,
85}
86
87impl<T> RaceBatch<T>
88where
89 T: Send + 'static,
90{
91 pub fn new(max_concurrent_jobs: NonZeroUsize) -> Self {
92 RaceBatch {
93 tasks: JoinSet::new(),
94 semaphore: Arc::new(Semaphore::new(max_concurrent_jobs.get())),
95 }
96 }
97
98 pub fn add(&mut self, future: impl Future<Output = anyhow::Result<T>> + Send + 'static) {
99 let sem = self.semaphore.clone();
100 self.tasks.spawn(async move {
101 let permit = sem
102 .acquire_owned()
103 .await
104 .context("Semaphore unexpectedly closed")?;
105 let result = future.await;
106 drop(permit);
107 result
108 });
109 }
110
111 pub async fn get_ok_validated<F>(mut self, validate: F) -> Option<T>
113 where
114 F: Fn(&T) -> bool,
115 {
116 while let Some(result) = self.tasks.join_next().await {
117 if let Ok(Ok(value)) = result
118 && validate(&value)
119 {
120 return Some(value);
121 }
122 }
123 None
125 }
126}
127
128impl SyncNetworkContext {
129 pub fn peer_manager(&self) -> &PeerManager {
131 self.peer_manager.as_ref()
132 }
133
134 pub fn network_send(&self) -> &flume::Sender<NetworkMessage> {
136 &self.network_send
137 }
138
139 pub async fn chain_exchange_headers(
143 &self,
144 peer_id: Option<PeerId>,
145 tsk: &TipsetKey,
146 count: NonZeroU64,
147 ) -> anyhow::Result<Vec<Tipset>> {
148 self.handle_chain_exchange_request(peer_id, tsk, count, HEADERS, |tipsets| {
149 validate_network_tipsets(tipsets, tsk)
150 })
151 .await
152 }
153
154 pub async fn chain_exchange_messages(
157 &self,
158 peer_id: Option<PeerId>,
159 ts: &Tipset,
160 ) -> anyhow::Result<FullTipset> {
161 let mut bundles: Vec<TipsetBundle> = self
162 .handle_chain_exchange_request(peer_id, ts.key(), nonzero!(1_u64), MESSAGES, |_| true)
163 .await?;
164
165 if bundles.len() != 1 {
166 anyhow::bail!(
167 "chain exchange request returned {} tipsets, 1 expected.",
168 bundles.len()
169 );
170 }
171 let mut bundle = bundles.remove(0);
172 bundle.blocks = ts.block_headers().to_vec();
173 bundle.try_into()
174 }
175
176 pub async fn chain_exchange_full_tipset(
180 &self,
181 peer_id: Option<PeerId>,
182 tsk: &TipsetKey,
183 ) -> anyhow::Result<FullTipset> {
184 let mut fts = self
185 .handle_chain_exchange_request(
186 peer_id,
187 tsk,
188 nonzero!(1_u64),
189 HEADERS | MESSAGES,
190 |tipsets| validate_network_tipsets(tipsets, tsk),
191 )
192 .await?;
193
194 anyhow::ensure!(
195 fts.len() == 1,
196 "Full tipset request returned {} tipsets, 1 expected.",
197 fts.len()
198 );
199
200 Ok(fts.remove(0))
201 }
202
203 pub async fn chain_exchange_full_tipsets(
204 &self,
205 peer_id: Option<PeerId>,
206 tsk: &TipsetKey,
207 ) -> anyhow::Result<Vec<FullTipset>> {
208 self.handle_chain_exchange_request(
209 peer_id,
210 tsk,
211 nonzero!(16_u64),
212 HEADERS | MESSAGES,
213 |_| true,
214 )
215 .await
216 }
217
218 pub async fn handle_chain_exchange_request<T, F>(
221 &self,
222 peer_id: Option<PeerId>,
223 tsk: &TipsetKey,
224 request_len: NonZeroU64,
225 options: u64,
226 validate: F,
227 ) -> anyhow::Result<Vec<T>>
228 where
229 T: TryFrom<TipsetBundle> + Send + Sync + 'static,
230 <T as TryFrom<TipsetBundle>>::Error: Into<anyhow::Error>,
231 F: Fn(&Vec<T>) -> bool,
232 {
233 let request = ChainExchangeRequest {
234 start: tsk.to_cids(),
235 request_len: request_len.get(),
236 options,
237 };
238
239 let global_pre_time = Instant::now();
240 let network_failures = Arc::new(AtomicU64::new(0));
241 let lookup_failures = Arc::new(AtomicU64::new(0));
242 let chain_exchange_result = match peer_id {
243 Some(id) => Self::chain_exchange_request(
245 self.peer_manager.clone(),
246 self.network_send.clone(),
247 id,
248 request,
249 )
250 .await?
251 .into_result()?,
252 None => {
253 let peers = self.peer_manager.top_peers_shuffled();
256 anyhow::ensure!(
257 !peers.is_empty(),
258 "chain exchange failed: no peers are available"
259 );
260
261 let n_peers = peers.len();
262 let mut batch = RaceBatch::new(*MAX_CONCURRENT_CHAIN_EXCHANGE_REQUESTS);
263 let success_time_cost_millis_stats = Arc::new(Mutex::new(Stats::new()));
264 for peer_id in peers.into_iter() {
265 let peer_manager = self.peer_manager.clone();
266 let network_send = self.network_send.clone();
267 let request = request.clone();
268 let network_failures = network_failures.clone();
269 let lookup_failures = lookup_failures.clone();
270 let success_time_cost_millis_stats = success_time_cost_millis_stats.clone();
271 batch.add(async move {
272 let start = Instant::now();
273 match Self::chain_exchange_request(
274 peer_manager,
275 network_send,
276 peer_id,
277 request,
278 )
279 .await
280 {
281 Ok(chain_exchange_result) => {
282 match chain_exchange_result.into_result::<T>() {
283 Ok(r) => {
284 success_time_cost_millis_stats.lock().update(
285 start.elapsed().as_millis()
286 );
287 Ok(r)
288 }
289 Err(error) => {
290 lookup_failures.fetch_add(1, Ordering::Relaxed);
291 debug!(%peer_id, %request_len, %options, %n_peers, %error, "Failed chain_exchange response");
292 Err(error)
293 }
294 }
295 }
296 Err(error) => {
297 network_failures.fetch_add(1, Ordering::Relaxed);
298 debug!(%peer_id, %request_len, %options, %n_peers, %error, "Failed chain_exchange request to peer");
299 Err(error)
300 }
301 }
302 });
303 }
304
305 let make_failure_message = || {
306 CHAIN_EXCHANGE_TIMEOUT_MILLIS.adapt_on_failure();
307 tracing::debug!(
308 "Increased chain exchange timeout to {}ms",
309 CHAIN_EXCHANGE_TIMEOUT_MILLIS.get()
310 );
311 let mut message = String::new();
312 message.push_str("ChainExchange request failed for all top peers. ");
313 message.push_str(&format!(
314 "{} network failures, ",
315 network_failures.load(Ordering::Relaxed)
316 ));
317 message.push_str(&format!(
318 "{} lookup failures, ",
319 lookup_failures.load(Ordering::Relaxed)
320 ));
321 message.push_str(&format!("request:\n{request:?}"));
322 anyhow::anyhow!(message)
323 };
324
325 let v = batch
326 .get_ok_validated(validate)
327 .await
328 .ok_or_else(make_failure_message)?;
329 if let Ok(mean) = success_time_cost_millis_stats.lock().mean()
330 && CHAIN_EXCHANGE_TIMEOUT_MILLIS.adapt_on_success(mean as _)
331 {
332 tracing::debug!(
333 "Decreased chain exchange timeout to {}ms. Current average: {}ms",
334 CHAIN_EXCHANGE_TIMEOUT_MILLIS.get(),
335 mean,
336 );
337 }
338 trace!("Succeed: handle_chain_exchange_request");
339 v
340 }
341 };
342
343 self.peer_manager
345 .log_global_success(Instant::now().duration_since(global_pre_time));
346
347 Ok(chain_exchange_result)
348 }
349
350 async fn chain_exchange_request(
352 peer_manager: Arc<PeerManager>,
353 network_send: flume::Sender<NetworkMessage>,
354 peer_id: PeerId,
355 request: ChainExchangeRequest,
356 ) -> anyhow::Result<ChainExchangeResponse> {
357 trace!("Sending ChainExchange Request to {peer_id}");
358
359 let req_pre_time = Instant::now();
360
361 let (tx, rx) = flume::bounded(1);
362 if network_send
363 .send_async(NetworkMessage::ChainExchangeRequest {
364 peer_id,
365 request,
366 response_channel: tx,
367 })
368 .await
369 .is_err()
370 {
371 anyhow::bail!("Failed to send chain exchange request to network");
372 };
373
374 let res = tokio::task::spawn_blocking(move || {
378 rx.recv_timeout(Duration::from_millis(CHAIN_EXCHANGE_TIMEOUT_MILLIS.get()))
379 })
380 .await;
381 let res_duration = Instant::now().duration_since(req_pre_time);
382 match res {
383 Ok(Ok(Ok(bs_res))) => {
384 peer_manager.log_success(&peer_id, res_duration);
386 trace!("Succeeded: ChainExchange Request to {peer_id}");
387 Ok(bs_res)
388 }
389 Ok(Ok(Err(e))) => {
390 match e {
392 RequestResponseError::UnsupportedProtocols => {
393 peer_manager
395 .ban_peer_with_default_duration(
396 peer_id,
397 "ChainExchange protocol unsupported",
398 |_| None,
399 )
400 .await;
401 }
402 RequestResponseError::ConnectionClosed | RequestResponseError::DialFailure => {
403 peer_manager.mark_peer_bad(peer_id, format!("chain exchange error {e:?}"));
404 }
405 RequestResponseError::Timeout | RequestResponseError::Io(_) => {
408 peer_manager.log_failure(&peer_id, res_duration);
409 }
410 }
411 debug!("Failed: ChainExchange Request to {peer_id}");
412 anyhow::bail!("Internal libp2p error: {e:?}");
413 }
414 Ok(Err(_)) | Err(_) => {
415 peer_manager.log_failure(&peer_id, res_duration);
418 debug!("Timeout: ChainExchange Request to {peer_id}");
419 anyhow::bail!("Chain exchange request to {peer_id} timed out");
420 }
421 }
422 }
423
424 pub async fn hello_request(
427 &self,
428 peer_id: PeerId,
429 request: HelloRequest,
430 ) -> anyhow::Result<(PeerId, Instant, Option<HelloResponse>)> {
431 trace!("Sending Hello Message to {}", peer_id);
432
433 let (tx, rx) = flume::bounded(1);
435
436 self.network_send
438 .send_async(NetworkMessage::HelloRequest {
439 peer_id,
440 request,
441 response_channel: tx,
442 })
443 .await
444 .context("Failed to send hello request: receiver dropped")?;
445
446 const HELLO_TIMEOUT: Duration = Duration::from_secs(30);
447 let sent = Instant::now();
448 let res = tokio::task::spawn_blocking(move || rx.recv_timeout(HELLO_TIMEOUT))
449 .await?
450 .ok();
451 Ok((peer_id, sent, res))
452 }
453}
454
455fn validate_network_tipsets<T: TipsetLike>(tipsets: &[T], start_tipset_key: &TipsetKey) -> bool {
459 if let Some(start) = tipsets.first() {
460 if start.key() != start_tipset_key {
461 tracing::warn!(epoch=%start.epoch(), expected=%start_tipset_key, actual=%start.key(), "start tipset key mismatch");
462 return false;
463 }
464 for (ts, pts) in tipsets.iter().zip(tipsets.iter().skip(1)) {
465 if ts.parents() != pts.key() {
466 tracing::warn!(epoch=%ts.epoch(), expected_parent=%pts.key(), actual_parent=%ts.parents(), "invalid chain");
467 return false;
468 }
469 }
470 true
471 } else {
472 tracing::warn!("invalid empty chain_exchange_headers response");
473 false
474 }
475}
476
477#[cfg(test)]
478mod tests {
479 use super::*;
480
481 use std::sync::atomic::{AtomicBool, AtomicUsize};
482
483 impl<T> RaceBatch<T>
484 where
485 T: Send + 'static,
486 {
487 pub async fn get_ok(self) -> Option<T> {
488 self.get_ok_validated(|_| true).await
489 }
490 }
491
492 #[tokio::test]
493 async fn race_batch_ok() {
494 let mut batch = RaceBatch::new(nonzero!(3_usize));
495 batch.add(async move { Ok(1) });
496 batch.add(async move { anyhow::bail!("kaboom") });
497
498 assert_eq!(batch.get_ok().await, Some(1));
499 }
500
501 #[tokio::test]
502 async fn race_batch_ok_faster() {
503 let mut batch = RaceBatch::new(nonzero!(3_usize));
504 batch.add(async move {
505 tokio::time::sleep(Duration::from_secs(100)).await;
506 Ok(1)
507 });
508 batch.add(async move { Ok(2) });
509 batch.add(async move { anyhow::bail!("kaboom") });
510
511 assert_eq!(batch.get_ok().await, Some(2));
512 }
513
514 #[tokio::test]
515 async fn race_batch_none() {
516 let mut batch: RaceBatch<i32> = RaceBatch::new(nonzero!(3_usize));
517 batch.add(async move { anyhow::bail!("kaboom") });
518 batch.add(async move { anyhow::bail!("banana") });
519
520 assert_eq!(batch.get_ok().await, None);
521 }
522
523 #[tokio::test]
524 async fn race_batch_semaphore() {
525 const MAX_JOBS: NonZeroUsize = nonzero!(30_usize);
526 let counter = Arc::new(AtomicUsize::new(0));
527 let exceeded = Arc::new(AtomicBool::new(false));
528
529 let mut batch: RaceBatch<i32> = RaceBatch::new(MAX_JOBS);
530 for _ in 0..10000 {
531 let c = counter.clone();
532 let e = exceeded.clone();
533 batch.add(async move {
534 let prev = c.fetch_add(1, Ordering::Relaxed);
535 if prev >= MAX_JOBS.get() {
536 e.fetch_or(true, Ordering::Relaxed);
537 }
538
539 tokio::task::yield_now().await;
540 c.fetch_sub(1, Ordering::Relaxed);
541
542 anyhow::bail!("banana")
543 });
544 }
545
546 assert_eq!(batch.get_ok().await, None);
547 assert!(!exceeded.load(Ordering::Relaxed));
548 }
549
550 #[tokio::test]
551 async fn race_batch_semaphore_exceeded() {
552 const MAX_JOBS: NonZeroUsize = nonzero!(30_usize);
553 let counter = Arc::new(AtomicUsize::new(0));
554 let exceeded = Arc::new(AtomicBool::new(false));
555
556 let mut batch: RaceBatch<i32> = RaceBatch::new(MAX_JOBS.checked_add(1).unwrap());
558 for _ in 0..10000 {
559 let c = counter.clone();
560 let e = exceeded.clone();
561 batch.add(async move {
562 let prev = c.fetch_add(1, Ordering::Relaxed);
563 if prev >= MAX_JOBS.get() {
564 e.fetch_or(true, Ordering::Relaxed);
565 }
566
567 tokio::task::yield_now().await;
568 c.fetch_sub(1, Ordering::Relaxed);
569
570 anyhow::bail!("banana")
571 });
572 }
573
574 assert_eq!(batch.get_ok().await, None);
575 assert!(exceeded.load(Ordering::Relaxed));
576 }
577
578 #[test]
579 #[allow(unused_variables)]
580 fn validate_network_tipsets_tests() {
581 use crate::blocks::{Chain4U, chain4u};
582
583 let c4u = Chain4U::new();
584 chain4u! {
585 in c4u;
586 t0 @ [genesis_header]
587 -> t1 @ [first_header]
588 -> t2 @ [second_left, second_right]
589 -> t3 @ [third]
590 -> t4 @ [fourth]
591 };
592 assert!(validate_network_tipsets(
593 &[t4.clone(), t3.clone(), t2.clone(), t1.clone(), t0.clone()],
594 t4.key()
595 ));
596 assert!(!validate_network_tipsets(
597 &[t4.clone(), t3.clone(), t2.clone(), t1.clone(), t0.clone()],
598 t3.key()
599 ));
600 assert!(!validate_network_tipsets(
601 &[t4.clone(), t2.clone(), t1.clone(), t0.clone()],
602 t4.key()
603 ));
604 }
605}