From 788f6032f31db3eb55dd5ec68623f5483706737b Mon Sep 17 00:00:00 2001 From: ivanjermakov Date: Mon, 6 Nov 2023 23:32:02 +0100 Subject: [PATCH] Peer metainfo --- src/extension.rs | 31 ++++++ src/main.rs | 3 +- src/metainfo.rs | 36 +++---- src/peer.rs | 218 ++++++++++++++++++++++++++++++++----------- src/peer_metainfo.rs | 109 ++++++++++++++++++++++ src/state.rs | 12 ++- src/torrent.rs | 8 +- src/tracker.rs | 102 ++++++++++---------- 8 files changed, 390 insertions(+), 129 deletions(-) create mode 100644 src/peer_metainfo.rs diff --git a/src/extension.rs b/src/extension.rs index a5a7d48..1867289 100644 --- a/src/extension.rs +++ b/src/extension.rs @@ -1,10 +1,19 @@ +use anyhow::{Context, Error}; + use crate::bencode::BencodeValue; +#[derive(Clone, Debug, PartialEq, Eq, PartialOrd, Ord, Hash)] pub enum Extension { Metadata, } impl Extension { + pub fn id(&self) -> usize { + match self { + Extension::Metadata => 1, + } + } + pub fn name(&self) -> String { match &self { Extension::Metadata => "ut_metadata".into(), @@ -28,3 +37,25 @@ impl Extension { ) } } + +impl TryFrom for Extension { + type Error = Error; + + fn try_from(value: usize) -> Result { + [Extension::Metadata] + .into_iter() + .find(|e| e.id() == value) + .context("unknown id") + } +} + +impl TryFrom<&str> for Extension { + type Error = Error; + + fn try_from(value: &str) -> Result { + match value { + "ut_metadata" => Ok(Extension::Metadata), + _ => Err(Error::msg("unknown extension")), + } + } +} diff --git a/src/main.rs b/src/main.rs index 3f6826d..c96dea6 100644 --- a/src/main.rs +++ b/src/main.rs @@ -19,6 +19,7 @@ mod feature; mod hex; mod metainfo; mod peer; +mod peer_metainfo; mod persist; mod sha1; mod state; @@ -48,7 +49,7 @@ async fn try_main() -> Result<()> { let config = Config { port: 6881, - respect_choke: true, + respect_choke: false, choke_wait: Duration::from_secs(10), reconnect_wait: Duration::from_secs(20), downloaded_check_wait: Duration::from_secs(1), diff --git a/src/metainfo.rs b/src/metainfo.rs index 56615b8..e8e8221 100644 --- a/src/metainfo.rs +++ b/src/metainfo.rs @@ -1,12 +1,14 @@ use core::fmt; use std::path::PathBuf; +use anyhow::{Error, Result}; + use crate::{bencode::BencodeValue, state::PieceHash}; #[derive(Clone, Debug, PartialEq, PartialOrd, Hash)] pub struct Metainfo { pub info: Info, - pub announce: String, + pub announce: Option, pub announce_list: Option>>, pub creation_date: Option, pub comment: Option, @@ -64,24 +66,24 @@ pub struct PathInfo { } impl TryFrom for Metainfo { - type Error = String; + type Error = Error; fn try_from(value: BencodeValue) -> Result { let dict = match value { BencodeValue::Dict(d) => d, - _ => return Err("metafile is not a dict".into()), + _ => return Err(Error::msg("metafile is not a dict")), }; let info_dict = match dict.get("info") { Some(BencodeValue::Dict(d)) => d, - _ => return Err("'info' is not a dict".into()), + _ => return Err(Error::msg("'info' is not a dict")), }; let pieces: Vec = match info_dict.get("pieces") { Some(BencodeValue::String(s)) => s.chunks(20).map(|c| PieceHash(c.to_vec())).collect(), - _ => return Err("'pieces' missing".into()), + _ => return Err(Error::msg("'pieces' missing")), }; let name: String = match info_dict.get("name") { Some(BencodeValue::String(s)) => String::from_utf8_lossy(s).into(), - _ => return Err("'name' missing".into()), + _ => return Err(Error::msg("'name' missing")), }; let file_info = match info_dict.get("files") { Some(d) => FileInfo::Multi(parse_files_info(d)?), @@ -89,7 +91,7 @@ impl TryFrom for Metainfo { path: PathBuf::from(&name), length: match info_dict.get("length") { Some(BencodeValue::Int(v)) => *v as u64, - _ => return Err("'length' missing".into()), + _ => return Err(Error::msg("'length' missing")), }, md5_sum: match info_dict.get("md5_sum") { Some(BencodeValue::String(s)) => Some(String::from_utf8_lossy(s).to_string()), @@ -101,7 +103,7 @@ impl TryFrom for Metainfo { info: Info { piece_length: match info_dict.get("piece length") { Some(BencodeValue::Int(v)) => *v as u64, - _ => return Err("'piece length' missing".into()), + _ => return Err(Error::msg("'piece length' missing")), }, pieces, name, @@ -112,8 +114,8 @@ impl TryFrom for Metainfo { }, }, announce: match dict.get("announce") { - Some(BencodeValue::String(s)) => String::from_utf8_lossy(s).into(), - _ => return Err("'announce' missing".into()), + Some(BencodeValue::String(s)) => Some(String::from_utf8_lossy(s).into()), + _ => None, }, announce_list: match dict.get("announce-list") { Some(BencodeValue::List(l)) => l @@ -152,7 +154,7 @@ impl TryFrom for Metainfo { } } -fn parse_files_info(value: &BencodeValue) -> Result, String> { +fn parse_files_info(value: &BencodeValue) -> Result> { match value { BencodeValue::List(l) => l .iter() @@ -165,15 +167,15 @@ fn parse_files_info(value: &BencodeValue) -> Result, String> { BencodeValue::String(dir) => { Ok(PathBuf::from(String::from_utf8_lossy(dir).to_string())) } - _ => Err("'path' item is not a string".into()), + _ => Err(Error::msg("'path' item is not a string")), }) - .collect::>()?, - _ => return Err("'path' is not a list".into()), + .collect::>()?, + _ => return Err(Error::msg("'path' is not a list")), }; Ok(PathInfo { length: match d.get("length") { Some(BencodeValue::Int(v)) => *v as u64, - _ => return Err("'length' missing".into()), + _ => return Err(Error::msg("'length' missing")), }, path, md5_sum: match d.get("md5_sum") { @@ -184,9 +186,9 @@ fn parse_files_info(value: &BencodeValue) -> Result, String> { }, }) } - _ => Err("'files' item is not a dict".into()), + _ => Err(Error::msg("'files' item is not a dict")), }) .collect(), - _ => Err("'files' is not a list".into()), + _ => Err(Error::msg("'files' is not a list")), } } diff --git a/src/peer.rs b/src/peer.rs index e404114..72251f3 100644 --- a/src/peer.rs +++ b/src/peer.rs @@ -17,13 +17,15 @@ use crate::{ extension::Extension, feature::Feature, hex::hex, + metainfo::Metainfo, + peer_metainfo::{PeerMetainfoMessage, METAINFO_PIECE_SIZE}, sha1, state::{Block, Peer, PeerInfo, PeerStatus, State, TorrentStatus, BLOCK_SIZE}, torrent::write_piece, types::ByteString, }; -#[derive(Debug)] +#[derive(Debug, Clone)] pub enum Message { Handshake { info_hash: Vec, @@ -61,7 +63,7 @@ pub enum Message { }, Extended { ext_id: u8, - payload: Option, + payload: Option, }, } @@ -129,7 +131,7 @@ impl From for Vec { .concat(), Message::Port { port } => [u32tb(3).as_slice(), &[9], &port.to_be_bytes()].concat(), Message::Extended { ext_id, payload } => { - let p = payload.map(|p| p.encode()).unwrap_or_default(); + let p = payload.unwrap_or_default(); [u32tb(p.len() as u32 + 2).as_slice(), &[20], &[ext_id], &p].concat() } } @@ -276,12 +278,10 @@ pub async fn read_message(stream: &mut OwnedReadHalf) -> Result { }), 20 => { let ext_id = payload_p[0]; - let payload = match &payload_p[1..] { - &[] => None, - p => match parse_bencoded(p.to_vec()) { - (Some(v @ BencodeValue::Dict(..)), left) if left.is_empty() => Some(v), - _ => None, - }, + let payload = if payload_p.len() == 1 { + None + } else { + Some(payload_p[1..].to_vec()) }; Ok(Message::Extended { ext_id, payload }) } @@ -400,7 +400,7 @@ pub async fn do_handle_peer(peer: PeerInfo, state: Arc>) -> Result< &mut w_stream, Message::Extended { ext_id: 0, - payload: Some(Extension::handshake(&[Extension::Metadata])), + payload: Some(Extension::handshake(&[Extension::Metadata]).encode()), }, ) .await?; @@ -428,57 +428,101 @@ pub async fn write_loop( state: Arc>, ) -> Result<()> { loop { - { - let (config, p) = { - let state = state.lock().await; - (state.config.clone(), state.peers.get(&peer).cloned()) - }; - if config.respect_choke { - if let Some(p) = p { - if p.choked { - debug!("peer is choked, waiting"); - sleep(config.choke_wait).await; - continue; - } - } - } + let (config, p) = { + let state = state.lock().await; + ( + state.config.clone(), + state.peers.get(&peer).cloned().context("no peer")?, + ) + }; + if config.respect_choke && p.choked { + debug!("peer is choked, waiting"); + sleep(config.choke_wait).await; + continue; } - let next = state.lock().await.next_piece(); - match next { - Some(piece) => { - debug!("next request piece: {:?}", piece); - let total_blocks = piece.total_blocks(); - - let block_idxs = (0..total_blocks) - .filter(|i| !piece.blocks.contains_key(i)) - .collect::>(); - for i in block_idxs { - let request_msg = Message::Request { - piece_index: piece.index, - begin: i * BLOCK_SIZE, - length: if i == total_blocks - 1 && piece.length % BLOCK_SIZE != 0 { - piece.length % BLOCK_SIZE + let status = state.lock().await.status.clone(); + match status { + TorrentStatus::Metainfo => { + if let Some(ext_id) = p.extension_map.get(&Extension::Metadata).copied() { + let metainfo = state.lock().await.metainfo.clone(); + if let Err(m_state) = metainfo { + if let Some(i) = m_state.next_piece() { + debug!("requesting metainfo piece {}", i); + let msg = Message::Extended { + ext_id, + payload: Some(PeerMetainfoMessage::Request { piece: i }.into()), + }; + let v: Vec = PeerMetainfoMessage::Request { piece: i }.into(); + trace!("msg: {}, {}", hex(&v), String::from_utf8_lossy(&v)); + send_message(&mut stream, msg).await?; } else { - BLOCK_SIZE - }, + debug!("all metainfo pieces downloaded"); + let mut state = state.lock().await; + let data = m_state + .pieces + .into_values() + .flat_map(|b| b.0) + .collect::>(); + if let (Some(info_dict), _) = parse_bencoded(data) { + debug!("bencoded metainfo: {:?}", info_dict); + // since peer metainfo protocol only transfers info dict, it needs + // to be inserted into full metainfo dict + let metainfo_dict = BencodeValue::Dict( + [("info".into(), info_dict)].into_iter().collect(), + ); + match Metainfo::try_from(metainfo_dict) { + Ok(metainfo) => { + state.metainfo = Ok(metainfo); + info!("metainfo is downloaded: {:?}", state.metainfo); + state.status = TorrentStatus::Downloading; + } + Err(e) => { + panic!("unable to parse metainfo from bencoded: {:#}", e); + } + } + } else { + warn!("unable to parse bencoded metainfo"); + } + } + } else { + unreachable!("metainfo not available"); }; - send_message(&mut stream, request_msg).await?; } } - _ => { - let mut state = state.lock().await; - if state.status == TorrentStatus::Metainfo { - // TODO - info!("requesting metainfo"); + TorrentStatus::Downloading => { + let piece = state.lock().await.next_piece(); + if let Some(piece) = piece { + debug!("next request piece: {:?}", piece); + let total_blocks = piece.total_blocks(); + + let block_idxs = (0..total_blocks) + .filter(|i| !piece.blocks.contains_key(i)) + .collect::>(); + for i in block_idxs { + let request_msg = Message::Request { + piece_index: piece.index, + begin: i * BLOCK_SIZE, + length: if i == total_blocks - 1 && piece.length % BLOCK_SIZE != 0 { + piece.length % BLOCK_SIZE + } else { + BLOCK_SIZE + }, + }; + send_message(&mut stream, request_msg).await?; + } } else { info!("torrent is downloaded"); - state.status = TorrentStatus::Downloaded; - debug!("no more pieces to request, disconnecting"); + state.lock().await.status = TorrentStatus::Downloaded; + debug!("nothing else to do, disconnecting"); return Ok(()); } } - }; + _ => { + debug!("nothing else to do, disconnecting"); + return Ok(()); + } + } let wait = state.lock().await.config.piece_request_wait; sleep(wait).await; } @@ -506,7 +550,7 @@ async fn read_loop( }) => { let status = state.lock().await.status.clone(); if status != TorrentStatus::Downloading { - warn!("not accepting pieces with status {:?}", status); + debug!("not accepting pieces with status {:?}", status); continue; } if begin % BLOCK_SIZE != 0 { @@ -598,8 +642,76 @@ async fn read_loop( } _ => debug!("no peer {:?}", peer), }, - Ok(Message::Extended { ext_id, payload }) => { - debug!("got extended message: {}@{:?}", ext_id, payload); + Ok(Message::Extended { + ext_id, + payload: Some(payload), + }) => { + trace!("got extended message: #{}", ext_id,); + match ext_id { + 0 => { + debug!("got extended handshake"); + if let Some(BencodeValue::Dict(dict)) = parse_bencoded(payload).0 { + match dict.get("m") { + Some(BencodeValue::Dict(m_d)) => { + let ext_map = m_d + .iter() + .filter_map(|(k, v)| { + let ext = Extension::try_from(k.as_str()).ok()?; + let num = match v { + BencodeValue::Int(i) => *i as u8, + _ => { + return Err(Error::msg("ext id is not an int")) + .ok() + } + }; + Some((ext, num)) + }) + .collect(); + state + .lock() + .await + .peers + .get_mut(&peer) + .context("no peer")? + .extension_map = ext_map; + } + _ => debug!("no `m` key"), + } + }; + } + _ => match Extension::try_from(ext_id as usize) { + Ok(Extension::Metadata) => match PeerMetainfoMessage::try_from(payload) { + Ok(msg) => { + debug!("got metadata message {:?}", msg); + match msg { + PeerMetainfoMessage::Data { + piece, + total_size, + data, + } => { + let mut state = state.lock().await; + if let Err(m_state) = state.metainfo.as_mut() { + m_state.pieces.insert(piece, data); + m_state.total_size = Some(total_size); + debug!( + "new metainfo piece {}/{}", + m_state.pieces.len(), + total_size.div_ceil(METAINFO_PIECE_SIZE) + ); + } else { + debug!("metainfo already set"); + } + } + _ => { + debug!("unhandled metadata message {:?}", msg); + } + } + } + Err(e) => debug!("{e:#}"), + }, + Err(..) => debug!("unsupported extension id: #{}", ext_id), + }, + } } Ok(msg) => { debug!("no handler for message, skipping: {:?}", msg); diff --git a/src/peer_metainfo.rs b/src/peer_metainfo.rs new file mode 100644 index 0000000..e8dd0d0 --- /dev/null +++ b/src/peer_metainfo.rs @@ -0,0 +1,109 @@ +use std::collections::BTreeMap; + +use anyhow::{Context, Error}; + +use crate::{ + bencode::{parse_bencoded, BencodeValue}, + state::Block, +}; + +pub const METAINFO_PIECE_SIZE: usize = 1 << 14; + +#[derive(Clone, Debug, PartialEq, Default)] +pub struct MetainfoState { + pub total_size: Option, + pub pieces: BTreeMap, +} + +impl MetainfoState { + pub fn next_piece(&self) -> Option { + if self.total_size.is_none() { + Some(0) + } else { + (0..self.total_size?.div_ceil(METAINFO_PIECE_SIZE)) + .find(|i| !self.pieces.contains_key(i)) + } + } +} + +#[derive(Clone, Debug, PartialEq)] +pub enum PeerMetainfoMessage { + Request { + piece: usize, + }, + Data { + piece: usize, + total_size: usize, + data: Block, + }, + Reject, +} + +impl PeerMetainfoMessage { + pub fn msg_type(&self) -> u8 { + match self { + PeerMetainfoMessage::Request { .. } => 0, + PeerMetainfoMessage::Data { .. } => 1, + PeerMetainfoMessage::Reject => 2, + } + } +} + +impl From for Vec { + fn from(value: PeerMetainfoMessage) -> Self { + let msg_type = BencodeValue::from(value.msg_type() as i64); + match value { + PeerMetainfoMessage::Request { piece } => BencodeValue::Dict( + [ + ("msg_type".into(), msg_type), + ("piece".into(), BencodeValue::from(piece as i64)), + ] + .into_iter() + .collect(), + ) + .encode(), + PeerMetainfoMessage::Data { .. } => todo!(), + PeerMetainfoMessage::Reject => { + BencodeValue::Dict([("msg_type".into(), msg_type)].into_iter().collect()).encode() + } + } + } +} + +impl TryFrom> for PeerMetainfoMessage { + type Error = Error; + + fn try_from(value: Vec) -> Result { + let (dict, data) = match parse_bencoded(value) { + (Some(BencodeValue::Dict(d)), left) => (d, left), + _ => return Err(Error::msg("parse error")), + }; + let msg_type = dict.get("msg_type").context("no msg_type")?; + Ok(match msg_type { + BencodeValue::Int(0) => { + let piece = match dict.get("piece").context("no piece")? { + BencodeValue::Int(i) => *i as usize, + _ => return Err(Error::msg("unexpected piece")), + }; + PeerMetainfoMessage::Request { piece } + } + BencodeValue::Int(1) => { + let piece = match dict.get("piece").context("no piece")? { + BencodeValue::Int(i) => *i as usize, + _ => return Err(Error::msg("unexpected piece")), + }; + let total_size = match dict.get("total_size").context("no total_size")? { + BencodeValue::Int(i) => *i as usize, + _ => return Err(Error::msg("unexpected total_size")), + }; + PeerMetainfoMessage::Data { + piece, + total_size, + data: Block(data), + } + } + BencodeValue::Int(2) => PeerMetainfoMessage::Reject, + _ => return Err(Error::msg("unexpected msg_type")), + }) + } +} diff --git a/src/state.rs b/src/state.rs index e183265..725c166 100644 --- a/src/state.rs +++ b/src/state.rs @@ -7,8 +7,10 @@ use serde::{Deserialize, Serialize}; use crate::{ config::Config, + extension::Extension, hex::hex, metainfo::{Info, Metainfo}, + peer_metainfo::MetainfoState, tracker::TrackerResponseSuccess, types::ByteString, }; @@ -22,7 +24,7 @@ pub struct State { pub peer_id: Vec, pub peers: BTreeMap, pub status: TorrentStatus, - pub metainfo: Option, + pub metainfo: Result, pub tracker_response: Option, pub pieces: Option>, } @@ -59,7 +61,7 @@ pub struct Piece { impl Piece { pub fn total_blocks(&self) -> u32 { - (self.length as f64 / BLOCK_SIZE as f64).ceil() as u32 + self.length.div_ceil(BLOCK_SIZE) } } @@ -91,6 +93,7 @@ pub struct Peer { pub interested: bool, pub bitfield: Option>, pub dht_port: Option, + pub extension_map: BTreeMap, } impl Peer { @@ -104,6 +107,7 @@ impl Peer { interested: false, bitfield: None, dht_port: None, + extension_map: BTreeMap::new(), } } } @@ -155,11 +159,11 @@ pub fn init_pieces(info: &Info) -> BTreeMap { }) .collect::>(); let total_len = info.file_info.total_length(); - if info.pieces.len() != (total_len as f64 / info.piece_length as f64).ceil() as usize { + if info.pieces.len() != total_len.div_ceil(info.piece_length) as usize { warn!( "total length/piece size/piece count inconsistent: {} info pieces, {} expected", info.pieces.len(), - (total_len as f64 / info.piece_length as f64).ceil() + total_len.div_ceil(info.piece_length) ); } info.pieces diff --git a/src/torrent.rs b/src/torrent.rs index 09679e8..2482c8d 100644 --- a/src/torrent.rs +++ b/src/torrent.rs @@ -8,6 +8,7 @@ use tokio::fs::File; use tokio::io::{AsyncSeekExt, AsyncWriteExt}; use tokio::{spawn, sync::Mutex}; +use crate::peer_metainfo::MetainfoState; use crate::types::ByteString; use crate::{ abort::EnsureAbort, @@ -55,19 +56,18 @@ pub async fn download_torrent( .await?; info!("discovered {} dht peers", peers.len()); - let pieces = init_pieces(&metainfo.info); let state = State { config: config.clone(), - metainfo: Some(metainfo), + metainfo: Err(MetainfoState::default()), tracker_response: None, info_hash, peer_id: p_state.lock().await.peer_id.to_vec(), - pieces: Some(pieces), + pieces: Some(init_pieces(&metainfo.info)), peers: peers .into_iter() .map(|p| (p.clone(), Peer::new(p))) .collect(), - status: TorrentStatus::Downloading, + status: TorrentStatus::Metainfo, }; let state = Arc::new(Mutex::new(state)); trace!("init state: {:?}", state); diff --git a/src/tracker.rs b/src/tracker.rs index 4f12982..d4c23d7 100644 --- a/src/tracker.rs +++ b/src/tracker.rs @@ -223,63 +223,65 @@ pub async fn tracker_request_http( pub async fn tracker_loop(state: Arc>) { loop { - let (announce, info_hash, peer_id, port, tracker_id, tracker_timeout) = { + if let (Some(announce), info_hash, peer_id, port, Some(tracker_id), Some(tracker_timeout)) = { let state = state.lock().await; ( - state.metainfo.as_ref().cloned().map(|m| m.announce), + state.metainfo.clone().ok().and_then(|m| m.announce), state.info_hash.clone(), state.peer_id.clone(), state.config.port, - state.tracker_response.clone().unwrap().tracker_id.clone(), - state.tracker_response.as_ref().map(|m| m.interval), + state + .tracker_response + .as_ref() + .map(|r| r.tracker_id.clone()), + state.tracker_response.as_ref().map(|r| r.interval), ) - }; - if announce.is_none() || tracker_timeout.is_none() { - debug!("tracker not available"); - sleep(Duration::from_secs(10)).await; - continue; - } - let tracker_response = tracker_request( - announce.unwrap(), - TrackerRequest::new(info_hash, peer_id, port, None, tracker_id), - ) - .await - .context("request failed"); - info!("tracker response: {tracker_response:?}"); + } { + let tracker_response = tracker_request( + announce, + TrackerRequest::new(info_hash, peer_id, port, None, tracker_id), + ) + .await + .context("request failed"); + info!("tracker response: {tracker_response:?}"); - // TODO: in case of error, try trackers from announce-list - match tracker_response { - Ok(TrackerResponse::Success(resp)) => { - let mut state = state.lock().await; - let new_peers: Vec<_> = resp - .peers - .into_iter() - .filter(|p| !state.peers.contains_key(p)) - .map(Peer::new) - .collect(); - info!("received {} new peers", new_peers.len()); - for p in new_peers { - state.peers.insert(p.info.clone(), p); - } - info!( - "total {} peers, {} connected", - state.peers.len(), - state + // TODO: in case of error, try trackers from announce-list + match tracker_response { + Ok(TrackerResponse::Success(resp)) => { + let mut state = state.lock().await; + let new_peers: Vec<_> = resp .peers - .values() - .filter(|p| p.status == PeerStatus::Connected) - .count() - ); - } - Ok(TrackerResponse::Failure { failure_reason }) => { - debug!("tracker failure: {}", failure_reason); - } - Err(e) => { - debug!("{e:#}"); - } - }; - - debug!("tracker timeout is {:?}", tracker_timeout); - sleep(Duration::from_secs(tracker_timeout.unwrap() as u64)).await; + .into_iter() + .filter(|p| !state.peers.contains_key(p)) + .map(Peer::new) + .collect(); + info!("received {} new peers", new_peers.len()); + for p in new_peers { + state.peers.insert(p.info.clone(), p); + } + info!( + "total {} peers, {} connected", + state.peers.len(), + state + .peers + .values() + .filter(|p| p.status == PeerStatus::Connected) + .count() + ); + } + Ok(TrackerResponse::Failure { failure_reason }) => { + debug!("tracker failure: {}", failure_reason); + } + Err(e) => { + debug!("{e:#}"); + } + }; + debug!("tracker timeout is {:?}", tracker_timeout); + sleep(Duration::from_secs(tracker_timeout as u64)).await; + } else { + let timeout = Duration::from_secs(10); + debug!("tracker not available, timeout is {:?}", timeout); + sleep(timeout).await; + } } }