Cache doesn't work for me

[ohrab-hacken]

I am running web3_proxy 1.43.11.
I want to test caching mechanism. The idea is to run local socat wich point to my private ethereum node and point web3_proxy to socat, instead of ethereum node. Make curl request to web_proxy 2 time. First time I should see log in the socat as web3_proxy need to request it from ethereum node, second time I should not see the log in the socat, as web3_proxy should return result from cache.
It doesn't work for me, as I see all requests in the socat log.

###How to reproduce
With the following command I am running websocket:

nohup socat -v -d tcp-listen:8546,reuseaddr,fork tcp:eth.hckn.dev:8545 &

Where eth.hckn.dev - private ethereum node.

Also, I running web3_proxy with the following config:

[app]
chain_id = 1

# no database
# no influxdb
# no redis
# no sentry
# no public limits means anon gets full access

# no thundering herd protection
min_sum_soft_limit = 1
min_synced_rpcs = 1

# 1GB of cache
response_cache_max_bytes = 1_000_000_000

[balanced_rpcs]

    [balanced_rpcs.geth_public_https]
    disabled = false
    display_name = "LlamaNodes HTTPS"
    http_url = "http://localhost:8546"
    soft_limit = 1_000

Where http://localhost:8546 is the address of local websocket.

The command to run web3_proxy:

nohup ./target/release/web3_proxy_cli proxyd &

Make the following curl request to web3_proxy:

curl -X POST -H "Content-Type: application/json" --data '{"jsonrpc":"2.0","method":"eth_getBalance", "params": ["0x0000000000000000000000000000000000000000", "latest"],"id":1}' http://10.1.193.21:8544

where 10.1.193.21 - ip address of the server where web3_proxy is running.

Take a look to the socat log with:

tail -f nohup.out

{"jsonrpc":"2.0","id":1,"method":"eth_getBalance","params":["0x0000000000000000000000000000000000000000","latest"]}< 2023/10/06 12:03:49.909157  length=180 from=5389775 to=5389954
HTTP/1.1 200 OK\r
Content-Type: application/json\r
Vary: Origin\r
Date: Fri, 06 Oct 2023 12:03:49 GMT\r
Content-Length: 58\r
\r
{"jsonrpc":"2.0","id":1,"result":"0x27d1ac00a42a537ecc1"}
> 2023/10/06 12:03:52.122826  length=266 from=244189 to=244454
POST / HTTP/1.1\r
content-type: application/json\r
accept: */*\r
user-agent: llamanodes_web3_proxy/v1.43.11\r
host: localhost:8546\r
content-length: 115\r
\r
{"jsonrpc":"2.0","id":1,"method":"eth_getBalance","params":["0x0000000000000000000000000000000000000000","latest"]}< 2023/10/06 12:03:52.123912  length=180 from=5389955 to=5390134
HTTP/1.1 200 OK\r
Content-Type: application/json\r
Vary: Origin\r
Date: Fri, 06 Oct 2023 12:03:52 GMT\r
Content-Length: 58\r
\r
{"jsonrpc":"2.0","id":1,"result":"0x27d1ac00a42a537ecc1"}
> 2023/10/06 12:03:55.636697  length=232 from=244455 to=244686
POST / HTTP/1.1\r
content-type: application/json\r
accept: */*\r
user-agent: llamanodes_web3_proxy/v1.43.11\r
host: localhost:8546\r
content-length: 82\r

Make curl requests multiple times. In the socat log you will see all the requests, but should see only the first one. As I understand cache mechanism doesn't work.

Could you please help me to understand what I am doing wrong, or it's expected behavior?

[BlinkyStitt]

Thank you for the detailed report. These requests should be cachable. We just made some changes for streaming that might be related. I'm working on another bug right now, but will get to this soon.

Thanks again!

[ohrab-hacken]

JFYI, tried with latest 1.43.15, and experienced the same behavior.

[BlinkyStitt]

Can you try again? We've released a LOT of changes

[ohrab-hacken]

Hey @wysenynja. Will try later on this week. I'll let you know the results.

[ohrab-hacken]

Hey @wysenynja. Just tested latest version on the same configuration. Looks like it's partially working. When I send first curl request, I see it in the socat logs, then multiple curl requests return from the cache(~8) - no entries about my curl on socat logs, then I see my request in the logs again, and next multiple requests return from the cache again(~12-15). It looks like it's cache the entries for multiple seconds only. I try cache with 1Gb and 10Gb, same behaviour. My expectation that cache will be present for longer time.

Could you please provide details how it should work, and where it is store the cache?

[BlinkyStitt]

Are all of your test queries always"eth_getBalance("0x0000000000000000000000000000000000000000","latest")? Because that is going to cache with the "latest" block which is constantly changing. So if that is the only query you are making, this seems to be working as intended. That response staying around for a long time would be bad.

Example:

1. You query eth_getBalance("0x0000000000000000000000000000000000000000", "latest")
2. We cache and send your current balance
3. You query again and get the cached response
4. A new block is mined. We can't tell without making a query if your balance changed, so we just have to ignore whatever was cached
5. You query eth_getBalance("0x0000000000000000000000000000000000000000", "latest") again and the backend is queried again.

[ohrab-hacken]

Hey @wysenynja, thx for the explanation. I've tried different curl requests now, which should be cached, but it doesn't:

curl -X POST -H "Content-Type: application/json" --data '{"jsonrpc":"2.0","method":"eth_getBlockByNumber", "params": ["latest",false],"id":100}' http://10.1.193.250:8544/

curl -X POST -H "Content-Type: application/json" --data '{"jsonrpc":"2.0","method":"eth_getBlockByNumber", "params": ["0x10",false],"id":100}' http://10.1.193.250:8544/

For each curl execution I see socat logs, so they don't cache. Do you know if such requests should be cached by web3_proxy?

[BlinkyStitt]

does it not cache at all, or does it not cache as often as you expect it to? because those should be cached. especially the second one

[ohrab-hacken]

@wysenynja eth_getBlockByNumber requests don't cache at all.