improve logging

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

web3_proxy/src/block_number.rs

@@ -32,10 +32,14 @@ pub fn clean_block_number(
     latest_block: U64,
 ) -> anyhow::Result<U64> {
     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"));
                 }
 

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,
                     ),

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())

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?

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
     }
 }