use super::one::Web3Rpc; use super::provider::Web3Provider; use crate::frontend::authorization::Authorization; use anyhow::Context; use chrono::Utc; use entities::revert_log; use entities::sea_orm_active_enums::Method; use ethers::providers::{HttpClientError, ProviderError, WsClientError}; use ethers::types::{Address, Bytes}; use log::{debug, error, trace, warn, Level}; use migration::sea_orm::{self, ActiveEnum, ActiveModelTrait}; use serde_json::json; use std::fmt; use std::sync::atomic; use std::sync::Arc; use thread_fast_rng::rand::Rng; use tokio::time::{sleep, Duration, Instant}; #[derive(Debug)] pub enum OpenRequestResult { Handle(OpenRequestHandle), /// Unable to start a request. Retry at the given time. RetryAt(Instant), /// Unable to start a request because no servers are synced NotReady, } /// Make RPC requests through this handle and drop it when you are done. /// Opening this handle checks rate limits. Developers, try to keep opening a handle and using it as close together as possible #[derive(Debug)] pub struct OpenRequestHandle { authorization: Arc, rpc: Arc, } /// Depending on the context, RPC errors can require different handling. #[derive(Copy, Clone)] pub enum RequestErrorHandler { /// Log at the trace level. Use when errors are expected. TraceLevel, /// Log at the debug level. Use when errors are expected. DebugLevel, /// Log at the error level. Use when errors are bad. ErrorLevel, /// Log at the warn level. Use when errors do not cause problems. WarnLevel, /// Potentially save the revert. Users can tune how often this happens SaveRevert, } // TODO: second param could be skipped since we don't need it here #[derive(serde::Deserialize, serde::Serialize)] struct EthCallParams((EthCallFirstParams, Option)); #[derive(serde::Deserialize, serde::Serialize)] struct EthCallFirstParams { to: Address, data: Option, } impl From for RequestErrorHandler { fn from(level: Level) -> Self { match level { Level::Trace => RequestErrorHandler::TraceLevel, Level::Debug => RequestErrorHandler::DebugLevel, Level::Error => RequestErrorHandler::ErrorLevel, Level::Warn => RequestErrorHandler::WarnLevel, _ => unimplemented!("unexpected tracing Level"), } } } impl Authorization { /// Save a RPC call that return "execution reverted" to the database. async fn save_revert( self: Arc, method: Method, params: EthCallFirstParams, ) -> anyhow::Result<()> { let rpc_key_id = match self.checks.rpc_secret_key_id { Some(rpc_key_id) => rpc_key_id.into(), None => { // // trace!(?self, "cannot save revert without rpc_key_id"); return Ok(()); } }; let db_conn = self.db_conn.as_ref().context("no database connection")?; // TODO: should the database set the timestamp? // we intentionally use "now" and not the time the request started // why? because we aggregate stats and setting one in the past could cause confusion let timestamp = Utc::now(); let to: Vec = params .to .as_bytes() .try_into() .expect("address should always convert to a Vec"); let call_data = params.data.map(|x| format!("{}", x)); let rl = revert_log::ActiveModel { rpc_key_id: sea_orm::Set(rpc_key_id), method: sea_orm::Set(method), to: sea_orm::Set(to), call_data: sea_orm::Set(call_data), timestamp: sea_orm::Set(timestamp), ..Default::default() }; let rl = rl .save(db_conn) .await .context("Failed saving new revert log")?; // TODO: what log level? // TODO: better format trace!("revert_log: {:?}", rl); // TODO: return something useful Ok(()) } } impl OpenRequestHandle { pub async fn new(authorization: Arc, rpc: Arc) -> Self { // TODO: take request_id as an argument? // TODO: attach a unique id to this? customer requests have one, but not internal queries // TODO: what ordering?! // TODO: should we be using metered, or not? i think not because we want stats for each handle // TODO: these should maybe be sent to an influxdb instance? rpc.active_requests.fetch_add(1, atomic::Ordering::Relaxed); Self { authorization, rpc } } pub fn connection_name(&self) -> String { self.rpc.name.clone() } #[inline] pub fn clone_connection(&self) -> Arc { self.rpc.clone() } /// Send a web3 request /// By having the request method here, we ensure that the rate limiter was called and connection counts were properly incremented /// depending on how things are locked, you might need to pass the provider in /// we take self to ensure this function only runs once pub async fn request( self, method: &str, params: &P, revert_handler: RequestErrorHandler, unlocked_provider: Option>, ) -> Result where // TODO: not sure about this type. would be better to not need clones, but measure and spawns combine to need it P: Clone + fmt::Debug + serde::Serialize + Send + Sync + 'static, R: serde::Serialize + serde::de::DeserializeOwned + fmt::Debug, { // TODO: use tracing spans // TODO: including params in this log is way too verbose // trace!(rpc=%self.rpc, %method, "request"); trace!("requesting from {}", self.rpc); let mut provider = if unlocked_provider.is_some() { unlocked_provider } else { self.rpc.provider.read().await.clone() }; let mut logged = false; while provider.is_none() || provider.as_ref().map(|x| !x.ready()).unwrap() { // trace!("waiting on provider: locking..."); // TODO: i dont like this. subscribing to a channel could be better sleep(Duration::from_millis(100)).await; if !logged { debug!("no provider for open handle on {}", self.rpc); logged = true; } provider = self.rpc.provider.read().await.clone(); } let provider = provider.expect("provider was checked already"); self.rpc .total_requests .fetch_add(1, std::sync::atomic::Ordering::Relaxed); self.rpc .active_requests .fetch_add(1, std::sync::atomic::Ordering::Relaxed); // let latency = Instant::now(); // TODO: replace ethers-rs providers with our own that supports streaming the responses let response = match provider.as_ref() { #[cfg(test)] Web3Provider::Mock => return Err(ProviderError::CustomError("mock provider can't respond".to_string())), Web3Provider::Ws(p) => p.request(method, params).await, Web3Provider::Http(p) | Web3Provider::Both(p, _) => { // TODO: i keep hearing that http is faster. but ws has always been better for me. investigate more with actual benchmarks p.request(method, params).await } }; // note. we intentionally do not record this latency now. we do NOT want to measure errors // let latency = latency.elapsed(); self.rpc .active_requests .fetch_sub(1, std::sync::atomic::Ordering::Relaxed); // // TODO: i think ethers already has trace logging (and does it much more fancy) // trace!( // "response from {} for {} {:?}: {:?}", // self.rpc, // method, // params, // response, // ); if let Err(err) = &response { // only save reverts for some types of calls // TODO: do something special for eth_sendRawTransaction too let error_handler = if let RequestErrorHandler::SaveRevert = revert_handler { // TODO: should all these be Trace or Debug or a mix? if !["eth_call", "eth_estimateGas"].contains(&method) { // trace!(%method, "skipping save on revert"); RequestErrorHandler::TraceLevel } else if self.authorization.db_conn.is_some() { let log_revert_chance = self.authorization.checks.log_revert_chance; if log_revert_chance == 0.0 { // trace!(%method, "no chance. skipping save on revert"); RequestErrorHandler::TraceLevel } else if log_revert_chance == 1.0 { // trace!(%method, "gaurenteed chance. SAVING on revert"); revert_handler } else if thread_fast_rng::thread_fast_rng().gen_range(0.0f64..=1.0) < log_revert_chance { // trace!(%method, "missed chance. skipping save on revert"); RequestErrorHandler::TraceLevel } else { // trace!("Saving on revert"); // TODO: is always logging at debug level fine? revert_handler } } else { // trace!(%method, "no database. skipping save on revert"); RequestErrorHandler::TraceLevel } } else { revert_handler }; // TODO: simple enum -> string derive? #[derive(Debug)] enum ResponseErrorType { Revert, RateLimit, Error, } // check for "execution reverted" here // TODO: move this info a function on ResponseErrorType let response_type = if let ProviderError::JsonRpcClientError(err) = err { // Http and Ws errors are very similar, but different types let msg = match &*provider { #[cfg(test)] Web3Provider::Mock => unimplemented!(), Web3Provider::Both(_, _) => { if let Some(HttpClientError::JsonRpcError(err)) = err.downcast_ref::() { Some(&err.message) } else if let Some(WsClientError::JsonRpcError(err)) = err.downcast_ref::() { Some(&err.message) } else { None } } Web3Provider::Http(_) => { if let Some(HttpClientError::JsonRpcError(err)) = err.downcast_ref::() { Some(&err.message) } else { None } } Web3Provider::Ws(_) => { if let Some(WsClientError::JsonRpcError(err)) = err.downcast_ref::() { Some(&err.message) } else { None } } }; if let Some(msg) = msg { if msg.starts_with("execution reverted") { trace!("revert from {}", self.rpc); ResponseErrorType::Revert } else if msg.contains("limit") || msg.contains("request") { trace!("rate limit from {}", self.rpc); ResponseErrorType::RateLimit } else { ResponseErrorType::Error } } else { ResponseErrorType::Error } } else { ResponseErrorType::Error }; match response_type { ResponseErrorType::RateLimit => { if let Some(hard_limit_until) = self.rpc.hard_limit_until.as_ref() { // TODO: how long? different providers have different rate limiting periods, though most seem to be 1 second // TODO: until the next second, or wait 1 whole second? let retry_at = Instant::now() + Duration::from_secs(1); trace!("retry {} at: {:?}", self.rpc, retry_at); hard_limit_until.send_replace(retry_at); } } ResponseErrorType::Error => { // TODO: should we just have Error or RateLimit? do we need Error and Revert separate? match error_handler { RequestErrorHandler::DebugLevel => { // TODO: include params only if not running in release mode debug!( "error response from {}! method={} params={:?} err={:?}", self.rpc, method, params, err ); } RequestErrorHandler::TraceLevel => { trace!( "error response from {}! method={} params={:?} err={:?}", self.rpc, method, params, err ); } RequestErrorHandler::ErrorLevel => { // TODO: include params only if not running in release mode error!( "error response from {}! method={} err={:?}", self.rpc, method, err ); } RequestErrorHandler::SaveRevert | RequestErrorHandler::WarnLevel => { // TODO: include params only if not running in release mode warn!( "error response from {}! method={} err={:?}", self.rpc, method, err ); } } } ResponseErrorType::Revert => { match error_handler { RequestErrorHandler::DebugLevel => { // TODO: include params only if not running in release mode debug!( "revert response from {}! method={} params={:?} err={:?}", self.rpc, method, params, err ); } RequestErrorHandler::TraceLevel => { trace!( "revert response from {}! method={} params={:?} err={:?}", self.rpc, method, params, err ); } RequestErrorHandler::ErrorLevel => { // TODO: include params only if not running in release mode error!( "revert response from {}! method={} err={:?}", self.rpc, method, err ); } RequestErrorHandler::WarnLevel => { // TODO: include params only if not running in release mode warn!( "revert response from {}! method={} err={:?}", self.rpc, method, err ); } RequestErrorHandler::SaveRevert => { trace!( "revert response from {}! method={} params={:?} err={:?}", self.rpc, method, params, err ); // TODO: do not unwrap! (doesn't matter much since we check method as a string above) let method: Method = Method::try_from_value(&method.to_string()).unwrap(); // TODO: DO NOT UNWRAP! But also figure out the best way to keep returning ProviderErrors here let params: EthCallParams = serde_json::from_value(json!(params)) .context("parsing params to EthCallParams") .unwrap(); // spawn saving to the database so we don't slow down the request let f = self.authorization.clone().save_revert(method, params.0 .0); tokio::spawn(f); } } } } // TODO: track error latency? } else { // TODO: record request latency // let latency_ms = start.elapsed().as_secs_f64() * 1000.0; // TODO: is this lock here a problem? should this be done through a channel? i started to code it, but it didn't seem to matter // let mut latency_recording = self.rpc.request_latency.write(); // latency_recording.record(latency_ms); } response } }