besu Besu warning

I'm running the besu node. Could you clarify me what does it mean in the log?

ethereum_1  | 2022-09-20 13:12:40.506+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)
ethereum_1  | 2022-09-20 13:12:40.508+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)
ethereum_1  | 2022-09-20 13:12:40.509+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)
ethereum_1  | 2022-09-20 13:12:40.511+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)
ethereum_1  | 2022-09-20 13:12:40.512+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)
ethereum_1  | 2022-09-20 13:12:40.513+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)
ethereum_1  | 2022-09-20 13:12:40.515+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)
ethereum_1  | 2022-09-20 13:12:40.516+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)
ethereum_1  | 2022-09-20 13:12:40.518+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)
ethereum_1  | 2022-09-20 13:12:40.519+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)
ethereum_1  | 2022-09-20 13:12:40.521+00:00 | vert.x-worker-thread-5 | WARN  | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)

docker-compose:

version: "3.5"
services:
  ethereum:
    image: hyperledger/besu:22.7.2
    network_mode: host
    volumes:
      - ./data:/opt/besu/database/
      - ./jwtsecret:/opt/besu/jwtsecret
    command:
      --network=mainnet
      --sync-mode=X_SNAP
      --data-storage-format=BONSAI
      --data-path="/opt/besu/database/"
      --rpc-http-max-active-connections=200
      --host-allowlist=*
      --rpc-http-enabled=true
      --rpc-http-host="0.0.0.0"
      --rpc-http-cors-origins="*"
      --rpc-ws-enabled=true
      --rpc-ws-host="0.0.0.0"
      --engine-host-allowlist="*"
      --nat-method=upnp
      --engine-rpc-port=8550
      --tx-pool-max-size=5000000
      --Xdns-enabled=true
      --Xmerge-support=true
      --engine-jwt-enabled=true
      --engine-jwt-secret=/opt/besu/jwtsecret
      --rpc-http-api=ETH,NET,CLIQUE,DEBUG,MINER,NET,PERM,ADMIN,EEA,TXPOOL,PRIV,WEB3,TRACE

Sep 20 '22 13:09 1scrooge

Not sure if a separate issue should be created for this, but we also see dramatical performance degradation after the Merge. Previously a block reading time (header, transactions, traces) took about 0.01-0.1 sec on a single node, now it takes about 5-15 sec on 3 nodes via a round-robin load balancer. Could you take a look on this as well or advice what can we do to improve performance back?

Sep 20 '22 13:09 1scrooge

ethereum_1 | 2022-09-20 13:12:40.506+00:00 | vert.x-worker-thread-5 | WARN | BonsaiWorldStateArchive | Exceeded the limit of back layers that can be loaded (512)

The warning is explained here: https://besu.hyperledger.org/en/stable/public-networks/concepts/data-storage-formats/#accessing-data Per default you can make requests only 512 blocks back.

Sep 24 '22 09:09 daniellehrner

Not sure if a separate issue should be created for this, but we also see dramatical performance degradation after the Merge. Previously a block reading time (header, transactions, traces) took about 0.01-0.1 sec on a single node, now it takes about 5-15 sec on 3 nodes via a round-robin load balancer. Could you take a look on this as well or advice what can we do to improve performance back?

Do you have any examples for the requests? We did not notice any performance degradation.

Sep 24 '22 09:09 daniellehrner

@daniellehrner Hi. we use these methods: eth_getBlockByNumber eth_getTransactionReceipt eth_getLogs eth_getTransactionByHash trace_transaction

Also I've changed the configuration --bonsai-maximum-back-layers-to-load=0 But we are still 512 blocks behind the network

Oct 04 '22 08:10 1scrooge

@daniellehrner Hello. I will explain a little bit what we are doing: We've tried to set --bonsai-maximum-back-layers-to-load to 64 and 16. The node starts work well after restart and return history up to 64 and 16 blocks old for a while. Then in several minutes of reading ongoing blocks from the node errors like

ethereum_1  | 2022-10-06 10:56:57.220+00:00 | vertx-blocked-thread-checker | WARN  | BlockedThreadChecker | Thread Thread[vert.x-worker-thread-15,5,main] has been blocked for 298951 ms, time limit is 60000 ms
ethereum_1  | io.vertx.core.VertxException: Thread blocked
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.vm.DebugOperationTracer.traceExecution(DebugOperationTracer.java:55)
ethereum_1  | 	at app//org.hyperledger.besu.evm.EVM.executeNextOperation(EVM.java:81)
ethereum_1  | 	at app//org.hyperledger.besu.evm.EVM.runToHalt(EVM.java:74)
ethereum_1  | 	at app//org.hyperledger.besu.evm.processor.AbstractMessageProcessor.codeExecute(AbstractMessageProcessor.java:161)
ethereum_1  | 	at app//org.hyperledger.besu.evm.processor.AbstractMessageProcessor.process(AbstractMessageProcessor.java:173)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor.process(MainnetTransactionProcessor.java:485)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor.processTransaction(MainnetTransactionProcessor.java:397)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor.processTransaction(MainnetTransactionProcessor.java:181)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.processor.BlockTracer.lambda$prepareReplayAction$0(BlockTracer.java:60)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.processor.BlockTracer$$Lambda$1231/0x00007fcbb55628b0.performAction(Unknown Source)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.processor.BlockReplay.lambda$block$0(BlockReplay.java:60)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.processor.BlockReplay$$Lambda$1243/0x00007fcbb5569568.apply(Unknown Source)
ethereum_1  | 	at [email protected]/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
ethereum_1  | 	at [email protected]/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655)
ethereum_1  | 	at [email protected]/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
ethereum_1  | 	at [email protected]/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
ethereum_1  | 	at [email protected]/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913)
ethereum_1  | 	at [email protected]/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
ethereum_1  | 	at [email protected]/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.processor.BlockReplay.lambda$block$1(BlockReplay.java:66)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.processor.BlockReplay$$Lambda$1232/0x00007fcbb556f458.perform(Unknown Source)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.processor.BlockReplay.performActionWithBlock(BlockReplay.java:155)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.processor.BlockReplay.block(BlockReplay.java:52)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.processor.BlockTracer.trace(BlockTracer.java:45)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.methods.AbstractTraceByHash.getTransactionTrace(AbstractTraceByHash.java:72)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.methods.AbstractTraceByHash.getTraceBlock(AbstractTraceByHash.java:65)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.methods.AbstractTraceByHash.lambda$resultByTransactionHash$1(AbstractTraceByHash.java:57)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.methods.AbstractTraceByHash$$Lambda$1228/0x00007fcbb55610b0.apply(Unknown Source)
ethereum_1  | 	at [email protected]/java.util.Optional.map(Optional.java:265)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.methods.AbstractTraceByHash.resultByTransactionHash(AbstractTraceByHash.java:57)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.internal.methods.TraceTransaction.response(TraceTransaction.java:53)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.execution.BaseJsonRpcProcessor.process(BaseJsonRpcProcessor.java:42)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.execution.TracedJsonRpcProcessor.process(TracedJsonRpcProcessor.java:41)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.execution.TimedJsonRpcProcessor.process(TimedJsonRpcProcessor.java:45)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.jsonrpc.execution.JsonRpcExecutor.execute(JsonRpcExecutor.java:91)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.handlers.JsonRpcExecutorHandler.lambda$handler$8(JsonRpcExecutorHandler.java:111)
ethereum_1  | 	at app//org.hyperledger.besu.ethereum.api.handlers.JsonRpcExecutorHandler$$Lambda$760/0x00007fcbcc9ea0b0.handle(Unknown Source)
ethereum_1  | 	at app//io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48)
ethereum_1  | 	at app//io.vertx.ext.web.impl.BlockingHandlerDecorator$$Lambda$954/0x00007fcbc78f2908.handle(Unknown Source)
ethereum_1  | 	at app//io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
ethereum_1  | 	at app//io.vertx.core.impl.ContextImpl$$Lambda$915/0x00007fcbc7efbcb0.handle(Unknown Source)
ethereum_1  | 	at app//io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
ethereum_1  | 	at app//io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
ethereum_1  | 	at app//io.vertx.core.impl.ContextImpl$$Lambda$914/0x00007fcbc7efd568.run(Unknown Source)
ethereum_1  | 	at [email protected]/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
ethereum_1  | 	at [email protected]/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
ethereum_1  | 	at app//io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
ethereum_1  | 	at [email protected]/java.lang.Thread.run(Thread.java:829)
ethereum_1  | 2022-10-06 10:56:57.222+00:00 | vertx-blocked-thread-checker | WARN  | BlockedThreadChecker | Thread Thread[vert.x-worker-thread-18,5,main] has been blocked for 298924 ms, time limit is 60000 ms
ethereum_1  | io.vertx.core.VertxException: Thread blocked

appear in the node and then eventually the node returns only up to 512 blocks old history. We do eth_getBlockByNumber first. If it returns a block, then we also execute eth_getTransactionReceipt, eth_getLogs, eth_getTransactionByHash, trace_transaction for the transactions of the block. If eth_getBlockByNumber don't return a block, then we call it one more time after a delay until it returns a block.

We do eth_getTransactionReceipt, eth_getLogs, eth_getTransactionByHash, trace_transaction invocations as batch by 4 parallel threads. Batch size is 100 methods

Oct 06 '22 11:10 1scrooge

Closing as we are tracking non-blocking RPC in #4807

Jan 26 '23 12:01 non-fungible-nelson

besu besu copied to clipboard

Besu warning

besu
besu copied to clipboard