more logging

TODO.md

@@ -294,11 +294,14 @@ These are not yet ordered. There might be duplicates. We might not actually need
 - [-] add configurable size limits to all the Caches
   - instead of configuring each cache with MB sizes, have one value for total memory footprint and then percentages for each cache
   - https://github.com/moka-rs/moka/issues/201
+- [-] ip detection needs work so that everything doesnt show up as 172.x.x.x
+  - i think this was done, but am not positive.
 - [ ] cli for adding rpc keys to an existing user
 - [ ] automatically tune database and redis connection pool size
 - [ ] if db is down, keep logins cached longer. at least only new logins will have trouble then
 - [ ] rate limiting/throttling on query_user_stats 
 - [ ] minimum allowed query_start on query_user_stats
+- [ ] during shutdown, mark the proxy unhealthy and send unsubscribe responses for any open websocket subscriptions
 - [ ] some chains still use total_difficulty. have total_difficulty be used only if the chain needs it
   - if total difficulty is not on the block and we aren't on ETH, fetch the full block instead of just the header
   - if total difficulty is set and non-zero, use it for consensus instead of just the number
@@ -461,9 +464,6 @@ in another repo: event subscriber
 
 ## "Maybe some day" and other Miscellaneous Things
 
-- [-] ip detection needs work so that everything doesnt show up as 172.x.x.x
-  - i think this was done, but am not positive.
-
 - [ ] tool to revoke bearer tokens that clears redis
 - [ ] eth_getBlockByNumber and similar calls served from the block map
   - will need all Block<TxHash> **and** Block<TransactionReceipt> in caches or fetched efficiently
@@ -578,3 +578,5 @@ in another repo: event subscriber
 - [ ] change invite codes to set the user_tier
 - [ ] some cli commands should use the replica if possible
 - [ ] some third party rpcs have limits on the size of eth_getLogs. include those limits in server config
+- [ ] some internal requests should go through app.proxy_rpc_request so that they get caching!
+    - be careful not to make an infinite loop

web3_proxy/src/block_number.rs

@@ -4,13 +4,13 @@ use ethers::{
     prelude::{BlockNumber, U64},
     types::H256,
 };
-use log::warn;
+use log::{trace, warn};
 use serde_json::json;
 use std::sync::Arc;
 
 use crate::{frontend::authorization::Authorization, rpcs::connections::Web3Connections};
 
-pub fn block_num_to_u64(block_num: BlockNumber, latest_block: U64) -> U64 {
+pub fn block_num_to_U64(block_num: BlockNumber, latest_block: U64) -> U64 {
     match block_num {
         BlockNumber::Earliest => {
             // modified is false because we want the backend to see "pending"
@@ -66,6 +66,8 @@ pub async fn clean_block_number(
                 Ok(latest_block)
             }
             Some(x) => {
+                let start = x.clone();
+
                 // convert the json value to a BlockNumber
                 let block_num = if let Some(obj) = x.as_object_mut() {
                     // it might be a Map like `{"blockHash": String("0xa5626dc20d3a0a209b1de85521717a3e859698de8ce98bca1b16822b7501f74b")}`
@@ -86,12 +88,17 @@ pub async fn clean_block_number(
                     // TODO: "BlockNumber" needs a better name
                     let block_number = serde_json::from_value::<BlockNumber>(x.take())?;
 
-                    block_num_to_u64(block_number, latest_block)
+                    block_num_to_U64(block_number, latest_block)
                 };
 
                 // if we changed "latest" to a number, update the params to match
                 *x = serde_json::to_value(block_num)?;
 
+                // TODO: only do this if trace logging is enabled
+                if x.as_u64() != start.as_u64() {
+                    trace!("changed {} to {}", start, x);
+                }
+
                 Ok(block_num)
             }
         },
@@ -161,7 +168,7 @@ pub async fn block_needed(
             if let Some(x) = obj.get_mut("fromBlock") {
                 let block_num: BlockNumber = serde_json::from_value(x.take())?;
 
-                let block_num = block_num_to_u64(block_num, head_block_num);
+                let block_num = block_num_to_U64(block_num, head_block_num);
 
                 *x = json!(block_num);
 
@@ -176,7 +183,7 @@ pub async fn block_needed(
             if let Some(x) = obj.get_mut("toBlock") {
                 let block_num: BlockNumber = serde_json::from_value(x.take())?;
 
-                let block_num = block_num_to_u64(block_num, head_block_num);
+                let block_num = block_num_to_U64(block_num, head_block_num);
 
                 *x = json!(block_num);
 

web3_proxy/src/rpcs/connections.rs

@@ -485,17 +485,16 @@ impl Web3Connections {
                 // increment our connection counter
                 match best_rpc.try_request_handle(authorization, false).await {
                     Ok(OpenRequestResult::Handle(handle)) => {
-                        // // trace!("next server on {:?}: {:?}", self, best_rpc);
+                        trace!("opened handle: {}", best_rpc);
                         return Ok(OpenRequestResult::Handle(handle));
                     }
                     Ok(OpenRequestResult::RetryAt(retry_at)) => {
                         earliest_retry_at = earliest_retry_at.min(Some(retry_at));
                     }
                     Ok(OpenRequestResult::NotReady) => {
-                        // TODO: log a warning?
+                        // TODO: log a warning? emit a stat?
                     }
                     Err(err) => {
-                        // TODO: log a warning?
                         warn!("No request handle for {}. err={:?}", best_rpc, err)
                     }
                 }
@@ -520,6 +519,8 @@ impl Web3Connections {
                 //     .await?;
                 // Ok(OpenRequestResult::Handle(handle))
 
+                // TODO: should we log here?
+
                 Ok(OpenRequestResult::NotReady)
             }
             Some(earliest_retry_at) => {

web3_proxy/src/rpcs/request.rs

@@ -236,7 +236,14 @@ impl OpenRequestHandle {
             Web3Provider::Ws(provider) => provider.request(method, params).await,
         };
 
-        // trace!("got response for {:?}: {:?}", self, response);
+        // TODO: i think ethers already has trace logging (and does it much more fancy)
+        trace!(
+            "response from {} for {} {:?}: {:?}",
+            self.conn,
+            method,
+            params,
+            response,
+        );
 
         if let Err(err) = &response {
             // only save reverts for some types of calls
@@ -307,6 +314,10 @@ impl OpenRequestHandle {
                 false
             };
 
+            if is_revert {
+                trace!("revert from {}", self.conn);
+            }
+
             // TODO: think more about the method and param logs. those can be sensitive information
             match error_handler {
                 RequestErrorHandler::DebugLevel => {
@@ -364,11 +375,6 @@ impl OpenRequestHandle {
                     tokio::spawn(f);
                 }
             }
-        } else {
-            // TODO: i think ethers already has trace logging (and does it much more fancy)
-            // TODO: opt-in response inspection to log reverts with their request. put into redis or what?
-            // // trace!(rpc=%self.conn, %method, ?response);
-            // trace!(%method, rpc=%self.conn, "response");
         }
 
         response