Invalid Block Range Params (rpc: get_logs)

[impactdni2]

Describe the bug
We're seeing RPC calls for get_logs fail randomly Happening on both 3.7.1, and 3.7.3.

eTo Reproduce Unfortunately, does not seem to be consistent. Started around 2 days ago (Sept 18th) on all of our servers (no code deploys in the last week). Manually requesting the same blocks/addresses afterward show the RPC call succeeds, so it seems transitory. During the periods where it fails, it fails for all the boxes at the same time.

Expected behavior
RPC returns correctly?

Additional context
Examples from two different RPC servers at the same times:

Sep 20 16:05:14 storage docker[93905]: INFO [09-20|16:05:14.890] created block                            l2Block=381,185,182 l2BlockHash=eb1981..21a64e
Sep 20 16:05:15 storage docker[93905]: WARN [09-20|16:05:15.431] Served eth_getLogs                       reqid=31174            duration="35.604µs"   err="invalid block range params"
Sep 20 16:05:15 storage docker[93905]: WARN [09-20|16:05:15.434] Served eth_getLogs                       reqid=34017            duration="35.291µs"   err="invalid block range params"
Sep 20 16:05:15 storage docker[93905]: INFO [09-20|16:05:15.891] created block                            l2Block=381,185,186 l2BlockHash=c16559..ea8157

Sep 20 16:05:14 storage2 docker[412787]: INFO [09-20|16:05:14.649] created block                            l2Block=381,185,181 l2BlockHash=95c324..d3d67a
Sep 20 16:05:15 storage2 docker[412787]: WARN [09-20|16:05:15.429] Served eth_getLogs                       reqid=19076 duration="40.265µs" err="invalid block range params"
Sep 20 16:05:15 storage2 docker[412787]: INFO [09-20|16:05:15.650] created block                            l2Block=381,185,185 l2BlockHash=82ebdc..451042

The specific request from servers was the following:
curl --request POST --url http://storage:8547 --header 'Content-Type: application/json' --data '{"method": "eth_getLogs","params": [{"fromBlock": "0x16b86c3d","toBlock":"0x16b86ca1","address":"0xD056aB60Ac2929fE6f40B5Ceb494A55e76a394cf","topics": []}],"id": 1,"jsonrpc": "2.0"}'
Which works properly when manually testing (after the failures)

From the timing and request numbers (in the example, toBlock = 381185185), it is possible that the toBlock number hasn't fully been processed yet on the server. The toBlock that we send is received from the same RPC connection, with a subscribe_blocks websocket.

Rough guess is that subscribe_blocks is sending a "we finished this block" message, but when immediately sending a get_logs request for that block, it hasn't finished indexing the logs, and says that block number is an invalid param?

[impactdni2]

We've temporarily worked around this issue by adding a 1s sleep between the subscribe_blocks notification, and requesting get_logs for that block.

[gligneul]

Hi @impactdni2. A few questions:

1. Which chain are you running? Arb1?
2. Is the connection directly to the Nitro node? Or is there a load balancer in between?

[impactdni2]

@gligneul

1. Yep, arb1
2. Directly connected (~100µs ping)

[gligneul]

Thanks @impactdni2, the team will look into it.

[gligneul]

Hi @impactdni2, the team discussed the issue, and we didn't consider this a bug. The node is an asynchronous system, and we can't guarantee synchronization between API calls. What we guarantee is eventual consistency, so if getLogs doesn't immediately find the block but eventually does, there isn't a bug.

We don't want to add this synchronization between API calls for two reasons. First, it could make the code more complicated, and we want to avoid that as much as possible. Second, it can make the newHeads notification slower for clients that don't need getLogs right after; we can't penalize everyone for a particular use case.

The approach of sleeping for one second works because this is a long timeout. Another thing you could do is implement a retrying mechanism. Most of the time, the getLogs should immediately work, but when it doesn't, the client waits a second and tries again.