polkadot-evm / frontier

Ethereum compatibility layer for Substrate.
Apache License 2.0
574 stars 487 forks source link

Performance of RPC response to `eth_getLogs` query seems to degrade as the chain grows. #416

Open nepoche opened 3 years ago

nepoche commented 3 years ago

Description

I am attempting to build a dApp on a substrate chain, Beresheet, which is using a version of frontier which has been forked off of commit 6e2e90833fdb9ee92f8e0a04fe0d217bfe07100d: https://github.com/webb-tools/frontier/tree/erup-4-update-master-substrate. https://github.com/hicommonwealth/edgeware-node/tree/erup-4-up-substrate-master

This dApp makes use of the eth_getLogs RPC call for previous interactions with a smart contract. I have noticed RPC requests performance degrades as the size of the blockchain increases. At the time of contract deployment (blockNumber ~5000), I was able to query in 1000 block increments and successfully receive responses. As the chain has grown (blockNumber ~167000 at time of writing), I receive timeouts for my RPC requests even when shrinking the range of block increments to 200 blocks.

Steps to Reproduce

  1. Deploy a smart contract and interact with it to generate some events.
  2. Make a call to the rpc using a script such as: https://github.com/webb-tools/evm-scripts/blob/5c65b89e6cb47b570b43a72e494809c50267ec52/scripts/ethers/viewPaginatedDepositEvents.js
    • Configure the block range to a size as big as possible while receiving successful responses to RPC requests.
  3. Wait 1 or 2 days for the blockchain to grow in size.
  4. Attempt to run the script again, and notice RPC requests start to fail.

Logs, Errors or Screenshots

Error: processing response error (body="{\"jsonrpc\":\"2.0\",\"error\":{\"code\":-32603,\"message\":\"query timeout of 10 seconds exceeded\"},\"id\":46}\n", error={"code":-32603}, requestBody="{\"method\":\"eth_getLogs\",\"params\":[{\"fromBlock\":\"0x1388\",\"toBlock\":\"0x1770\",\"address\":\"0x2ee2e51cab1561e4482cacc8be8b46ce61e46991\",\"topics\":[[\"0xa945e51eec50ab98c161376f0db4cf2aeba3ec92755fe2fcd388bdbbb80ff196\"]]}],\"id\":46,\"jsonrpc\":\"2.0\"}", requestMethod="POST", url="http://beresheet1.edgewa.re:9933", code=SERVER_ERROR, version=web/5.2.0)
    at Logger.makeError (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/logger/lib/index.js:187:21)
    at Logger.throwError (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/logger/lib/index.js:196:20)
    at /Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:266:32
    at step (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:33:23)
    at Object.next (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:14:53)
    at fulfilled (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:5:58)
    at processTicksAndRejections (node:internal/process/task_queues:94:5) {
  reason: 'processing response error',
  code: 'SERVER_ERROR',
  body: '{"jsonrpc":"2.0","error":{"code":-32603,"message":"query timeout of 10 seconds exceeded"},"id":46}\n',
  error: Error: query timeout of 10 seconds exceeded
      at getResult (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/providers/lib/json-rpc-provider.js:128:21)
      at processJsonFunc (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:309:22)
      at /Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:241:46
      at step (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:33:23)
      at Object.next (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:14:53)
      at fulfilled (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:5:58)
      at processTicksAndRejections (node:internal/process/task_queues:94:5) {
    code: -32603,
    data: undefined
  },
  requestBody: '{"method":"eth_getLogs","params":[{"fromBlock":"0x1388","toBlock":"0x1770","address":"0x2ee2e51cab1561e4482cacc8be8b46ce61e46991","topics":[["0xa945e51eec50ab98c161376f0db4cf2aeba3ec92755fe2fcd388bdbbb80ff196"]]}],"id":46,"jsonrpc":"2.0"}',
  requestMethod: 'POST',
  url: 'http://beresheet1.edgewa.re:9933'
}

I have noticed the following error as well, but less frequently than the former:

/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/logger/lib/index.js:187
        var error = new Error(message);
                    ^

Error: missing response (requestBody="{\"method\":\"eth_getLogs\",\"params\":[{\"fromBlock\":\"0x28870\",\"toBlock\":\"0x28938\",\"address\":\"0x2ee2e51cab1561e4482cacc8be8b46ce61e46991\",\"topics\":[[\"0xa945e51eec50ab98c161376f0db4cf2aeba3ec92755fe2fcd388bdbbb80ff196\"]]}],\"id\":708,\"jsonrpc\":\"2.0\"}", requestMethod="POST", serverError={"errno":-60,"code":"ETIMEDOUT","syscall":"connect","address":"207.148.19.178","port":9933}, url="http://beresheet3.edgewa.re:9933", code=SERVER_ERROR, version=web/5.2.0)
    at Logger.makeError (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/logger/lib/index.js:187:21)
    at Logger.throwError (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/logger/lib/index.js:196:20)
    at /Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:213:36
    at step (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:33:23)
    at Object.throw (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:14:53)
    at rejected (/Users/nathanbarnavon/workspace/evm-scripts/node_modules/@ethersproject/web/lib/index.js:6:65)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (node:internal/process/task_queues:94:5) {
  reason: 'missing response',
  code: 'SERVER_ERROR',
  requestBody: '{"method":"eth_getLogs","params":[{"fromBlock":"0x28870","toBlock":"0x28938","address":"0x2ee2e51cab1561e4482cacc8be8b46ce61e46991","topics":[["0xa945e51eec50ab98c161376f0db4cf2aeba3ec92755fe2fcd388bdbbb80ff196"]]}],"id":708,"jsonrpc":"2.0"}',
  requestMethod: 'POST',
  serverError: Error: connect ETIMEDOUT 207.148.19.178:9933
      at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1138:16) {
    errno: -60,
    code: 'ETIMEDOUT',
    syscall: 'connect',
    address: '207.148.19.178',
    port: 9933
  },
  url: 'http://beresheet3.edgewa.re:9933'
}
tgmichel commented 3 years ago

Tried to reproduce your issue here: https://github.com/PureStake/frontier/blob/tgm-426

Please build with manual-seal and run the typescript tests - it will run only test-chain-grow.ts (https://github.com/PureStake/frontier/blob/tgm-426/ts-tests/tests/test-chain-grow.ts). It took ~1 hour to run for me locally:

All requests received responses and no timeout errors were thrown, so I couldn't reproduce it. Should output something like this:

Created 5000 blocks, transact.
1
10001
20001
...
180001
190001
{
  jsonrpc: '2.0',
  result: [
    {
      address: '0xc2bf5f29a4384b1ab0c063e1c666f02121b6084a',
      blockHash: '0xd33d12ddba40a8d3f644342ae827dd355b46696b499c44189faac943dfdf1362',
      blockNumber: '0x1',
      data: '0xffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff',
      logIndex: '0x0',
      removed: false,
      topics: [Array],
      transactionHash: '0x049dac83a9d5274c6754f1b03f7b8753203c8c51e01c07b9c3da761ec0e3bd60',
      transactionIndex: '0x0',
      transactionLogIndex: '0x0'
    }
  ],
  id: 1
}
{ jsonrpc: '2.0', result: [], id: 1 }
{ jsonrpc: '2.0', result: [], id: 1 }
{ jsonrpc: '2.0', result: [], id: 1 }
..
{ jsonrpc: '2.0', result: [], id: 1 }
{ jsonrpc: '2.0', result: [], id: 1 }