From 501f2b0b2408a8115a992ba1ff9e675bd2a22bf9 Mon Sep 17 00:00:00 2001 From: Bryan Stitt Date: Sat, 10 Sep 2022 00:58:33 +0000 Subject: [PATCH] improve logging --- web3_proxy/src/app.rs | 6 +++++- web3_proxy/src/block_number.rs | 6 +++++- web3_proxy/src/frontend/errors.rs | 5 +++-- web3_proxy/src/frontend/users.rs | 5 ++++- web3_proxy/src/rpcs/connections.rs | 26 ++++++++++++-------------- web3_proxy/src/rpcs/request.rs | 20 ++++++++++---------- 6 files changed, 39 insertions(+), 29 deletions(-) diff --git a/web3_proxy/src/app.rs b/web3_proxy/src/app.rs index d0239ee5..68a7c317 100644 --- a/web3_proxy/src/app.rs +++ b/web3_proxy/src/app.rs @@ -790,6 +790,7 @@ impl Web3ProxyApp { Some(serde_json::Value::Array(params)) => { // TODO: make a struct and use serde conversion to clean this up if params.len() != 1 || !params[0].is_string() { + // TODO: this needs the correct error code in the response return Err(anyhow::anyhow!("invalid request")); } @@ -799,7 +800,10 @@ impl Web3ProxyApp { json!(hash) } - _ => return Err(anyhow::anyhow!("invalid request")), + _ => { + // TODO: this needs the correct error code in the response + return Err(anyhow::anyhow!("invalid request")); + } } } // anything else gets sent to backend rpcs and cached diff --git a/web3_proxy/src/block_number.rs b/web3_proxy/src/block_number.rs index 425ee657..7b833990 100644 --- a/web3_proxy/src/block_number.rs +++ b/web3_proxy/src/block_number.rs @@ -32,10 +32,14 @@ pub fn clean_block_number( latest_block: U64, ) -> anyhow::Result { match params.as_array_mut() { - None => Err(anyhow::anyhow!("params not an array")), + None => { + // TODO: this needs the correct error code in the response + Err(anyhow::anyhow!("params not an array")) + } Some(params) => match params.get_mut(block_param_id) { None => { if params.len() != block_param_id - 1 { + // TODO: this needs the correct error code in the response return Err(anyhow::anyhow!("unexpected params length")); } diff --git a/web3_proxy/src/frontend/errors.rs b/web3_proxy/src/frontend/errors.rs index bda3509f..6381e953 100644 --- a/web3_proxy/src/frontend/errors.rs +++ b/web3_proxy/src/frontend/errors.rs @@ -35,8 +35,9 @@ impl IntoResponse for FrontendErrorResponse { warn!(?err, "anyhow"); ( StatusCode::INTERNAL_SERVER_ERROR, - JsonRpcForwardedResponse::from_str( - "anyhow error!", + JsonRpcForwardedResponse::from_string( + // TODO: is it safe to expose all our anyhow strings? + err.to_string(), Some(StatusCode::INTERNAL_SERVER_ERROR.as_u16().into()), None, ), diff --git a/web3_proxy/src/frontend/users.rs b/web3_proxy/src/frontend/users.rs index 4ab00569..c4c6ba4b 100644 --- a/web3_proxy/src/frontend/users.rs +++ b/web3_proxy/src/frontend/users.rs @@ -102,7 +102,10 @@ pub async fn get_login( // https://github.com/spruceid/siwe/issues/98 "eip191_bytes" => Bytes::from(message.eip191_bytes().unwrap()).to_string(), "eip191_hash" => Bytes::from(&message.eip191_hash().unwrap()).to_string(), - _ => return Err(anyhow::anyhow!("invalid message eip given").into()), + _ => { + // TODO: this needs the correct error code in the response + return Err(anyhow::anyhow!("invalid message eip given").into()); + } }; Ok(message.into_response()) diff --git a/web3_proxy/src/rpcs/connections.rs b/web3_proxy/src/rpcs/connections.rs index de9b779a..c98fce85 100644 --- a/web3_proxy/src/rpcs/connections.rs +++ b/web3_proxy/src/rpcs/connections.rs @@ -492,9 +492,9 @@ impl Web3Connections { } match self .next_upstream_server(&skip_rpcs, min_block_needed) - .await + .await? { - Ok(OpenRequestResult::Handle(active_request_handle)) => { + OpenRequestResult::Handle(active_request_handle) => { // save the rpc in case we get an error and want to retry on another server skip_rpcs.push(active_request_handle.clone_connection()); @@ -535,19 +535,20 @@ impl Web3Connections { return Ok(response); } Err(e) => { - warn!(?self, ?e, "Backend server error!"); + let rpc = skip_rpcs + .last() + .expect("there must have been a provider if we got an error"); + + warn!(%rpc, ?e, "Backend server error! Retrying on another"); // TODO: sleep how long? until synced_connections changes or rate limits are available - sleep(Duration::from_millis(100)).await; + // sleep(Duration::from_millis(100)).await; - // TODO: when we retry, depending on the error, skip using this same server - // for example, if rpc isn't available on this server, retrying is bad - // but if an http error, retrying on same is probably fine continue; } } } - Ok(OpenRequestResult::RetryAt(retry_at)) => { + OpenRequestResult::RetryAt(retry_at) => { // TODO: move this to a helper function // sleep (TODO: with a lock?) until our rate limits should be available // TODO: if a server catches up sync while we are waiting, we could stop waiting @@ -557,7 +558,7 @@ impl Web3Connections { continue; } - Ok(OpenRequestResult::RetryNever) => { + OpenRequestResult::RetryNever => { warn!(?self, "No server handles!"); // TODO: subscribe to something on synced connections. maybe it should just be a watch channel @@ -565,13 +566,10 @@ impl Web3Connections { continue; } - Err(err) => { - return Err(err); - } } } - Err(anyhow::anyhow!("all retries exhausted")) + Err(anyhow::anyhow!("all {} tries exhausted", skip_rpcs.len())) } /// be sure there is a timeout on this or it might loop forever @@ -604,7 +602,7 @@ impl Web3Connections { return Ok(response); } Err(None) => { - warn!(?self, "No servers in sync!"); + warn!(?self, "No servers in sync! Retrying"); // TODO: i don't think this will ever happen // TODO: return a 502? if it does? diff --git a/web3_proxy/src/rpcs/request.rs b/web3_proxy/src/rpcs/request.rs index 6934bab2..7fe56465 100644 --- a/web3_proxy/src/rpcs/request.rs +++ b/web3_proxy/src/rpcs/request.rs @@ -94,26 +94,26 @@ impl OpenRequestHandle { } } - let response = match &*provider.unwrap() { + let response = match &*provider.expect("provider was checked already") { Web3Provider::Http(provider) => provider.request(method, params).await, Web3Provider::Ws(provider) => provider.request(method, params).await, }; - // TODO: i think ethers already has trace logging (and does it much more fancy) - if let Err(err) = &response { - warn!(?err, %method, rpc=%self.conn, "response"); - } else { - // trace!(rpc=%self.0, %method, ?response); - trace!(%method, rpc=%self.conn, "response"); - } - self.decremented.store(true, atomic::Ordering::Release); self.conn .active_requests .fetch_sub(1, atomic::Ordering::AcqRel); - // todo: do something to make sure this doesn't get called again? i miss having the function sig have self + // TODO: i think ethers already has trace logging (and does it much more fancy) + if let Err(err) = &response { + warn!(?err, %method, rpc=%self.conn, "bad response!"); + } else { + // TODO: opt-in response inspection to log reverts with their request. put into redis or what? + // trace!(rpc=%self.0, %method, ?response); + trace!(%method, rpc=%self.conn, "response"); + } + response } }