IllegalArgumentException: Must have at least one header to import #3336

fab-10 · 2022-01-27T14:07:24Z

Description

This exception occurs quite frequently, and it worth to investigate that there is a underlying issue

{
	"timestamp": "2022-01-27T13:55:36,788",
	"level": "ERROR",
	"thread": "EthScheduler-Services-16 (downloadHeaders)",
	"class": "PipelineChainDownloader",
	"message": "Chain download failed. Restarting after short delay.",
	"throwable": " java.util.concurrent.CompletionException: java.lang.RuntimeException: Async operation failed. java.lang.IllegalArgumentException: Must have at least one header to import
	at java.base/java.util.concurrent.CompletableFuture.encodeRelay(CompletableFuture.java:367)
	at java.base/java.util.concurrent.CompletableFuture.completeRelay(CompletableFuture.java:376)
	at java.base/java.util.concurrent.CompletableFuture$UniRelay.tryFire(CompletableFuture.java:1019)
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
	at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
	at org.hyperledger.besu.services.pipeline.Pipeline.abort(Pipeline.java:180)
	at org.hyperledger.besu.services.pipeline.Pipeline.lambda$runWithErrorHandling$3(Pipeline.java:159)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.RuntimeException: Async operation failed. java.lang.IllegalArgumentException: Must have at least one header to import
	at org.hyperledger.besu.services.pipeline.AsyncOperationProcessor.outputNextCompletedTask(AsyncOperationProcessor.java:86)
	at org.hyperledger.besu.services.pipeline.AsyncOperationProcessor.attemptFinalization(AsyncOperationProcessor.java:70)
	at org.hyperledger.besu.services.pipeline.ProcessingStage.run(ProcessingStage.java:43)
	at org.hyperledger.besu.services.pipeline.Pipeline.lambda$runWithErrorHandling$3(Pipeline.java:152)
	... 5 more
Caused by: java.util.concurrent.ExecutionException: java.lang.IllegalArgumentException: Must have at least one header to import
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2022)
	at org.hyperledger.besu.services.pipeline.AsyncOperationProcessor.waitForAnyFutureToComplete(AsyncOperationProcessor.java:94)
	at org.hyperledger.besu.services.pipeline.AsyncOperationProcessor.outputNextCompletedTask(AsyncOperationProcessor.java:81)
	... 8 more
Caused by: java.lang.IllegalArgumentException: Must have at least one header to import
	at com.google.common.base.Preconditions.checkArgument(Preconditions.java:145)
	at org.hyperledger.besu.ethereum.eth.sync.CheckpointRangeHeaders.<init>(CheckpointRangeHeaders.java:32)
	at org.hyperledger.besu.ethereum.eth.sync.DownloadHeadersStep.processHeaders(DownloadHeadersStep.java:118)
	at org.hyperledger.besu.ethereum.eth.sync.DownloadHeadersStep.lambda$apply$0(DownloadHeadersStep.java:67)
	at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:642)
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
	at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)
	at org.hyperledger.besu.ethereum.eth.manager.task.AbstractPeerRequestTask.lambda$executeTask$2(AbstractPeerRequestTask.java:83)
	at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859)
	at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837)
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
	at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)
	at java.base/java.util.Optional.ifPresent(Optional.java:183)
	at org.hyperledger.besu.ethereum.eth.manager.task.AbstractPeerRequestTask.handleMessage(AbstractPeerRequestTask.java:104)
	at org.hyperledger.besu.ethereum.eth.manager.task.AbstractPeerRequestTask.lambda$executeTask$0(AbstractPeerRequestTask.java:67)
	at org.hyperledger.besu.ethereum.eth.manager.RequestManager$ResponseStream.dispatchBufferedResponses(RequestManager.java:191)
	at org.hyperledger.besu.ethereum.eth.manager.RequestManager$ResponseStream.processMessage(RequestManager.java:182)
	at org.hyperledger.besu.ethereum.eth.manager.RequestManager.lambda$dispatchResponse$2(RequestManager.java:79)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at org.hyperledger.besu.ethereum.eth.manager.RequestManager.dispatchResponse(RequestManager.java:79)
	at org.hyperledger.besu.ethereum.eth.manager.EthPeer.lambda$dispatch$7(EthPeer.java:345)
	at java.base/java.util.Optional.ifPresentOrElse(Optional.java:201)
	at org.hyperledger.besu.ethereum.eth.manager.EthPeer.dispatch(EthPeer.java:344)
	at org.hyperledger.besu.ethereum.eth.manager.EthPeers.dispatchMessage(EthPeers.java:132)
	at org.hyperledger.besu.ethereum.eth.manager.EthProtocolManager.processMessage(EthProtocolManager.java:275)
	at org.hyperledger.besu.ethereum.p2p.network.NetworkRunner.lambda$setupHandlers$0(NetworkRunner.java:135)
	at org.hyperledger.besu.ethereum.p2p.rlpx.connections.PeerConnectionEvents.lambda$dispatchMessage$1(PeerConnectionEvents.java:64)
	at org.hyperledger.besu.util.Subscribers.lambda$forEach$0(Subscribers.java:112)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at org.hyperledger.besu.util.Subscribers.forEach(Subscribers.java:109)
	at org.hyperledger.besu.ethereum.p2p.rlpx.connections.PeerConnectionEvents.dispatchMessage(PeerConnectionEvents.java:64)
	at org.hyperledger.besu.ethereum.p2p.rlpx.connections.netty.ApiHandler.channelRead0(ApiHandler.java:99)
	at org.hyperledger.besu.ethereum.p2p.rlpx.connections.netty.ApiHandler.channelRead0(ApiHandler.java:33)
	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	... 1 more
"
}

Versions (Add all that apply)

Software version: 21.10.9
Java version: 11

The text was updated successfully, but these errors were encountered:

frankisawesome · 2022-03-08T01:21:50Z

Timeboxed to 8 March

iamhsk · 2022-04-28T02:38:31Z

Closing this issue since it is hard to reproduce. We added additional logging for better debugging in the future.

macfarla · 2022-05-11T01:12:00Z

This has happened again for a community user https://discord.com/channels/697535391594446898/888098626264502302/972551400296968192

kirillp · 2022-05-12T19:27:17Z

My besu log full of this messages

xrchz · 2022-07-13T06:25:01Z

Mine too - this happens all the time for my freshly synced 22.4.4.

ibhagwan · 2022-07-22T00:44:49Z

Same here, happens quite frequently:

❯ besu --version
besu/v22.4.4/linux-x86_64/openjdk-java-17

2022-07-21 20:32:47.926-04:00 | EthScheduler-Services-39 (downloadHeaders) | ERROR | PipelineChainDownloader | Chain download failed. Restarting after short delay.
java.util.concurrent.CompletionException: java.lang.RuntimeException: Async operation failed. java.lang.IllegalArgumentException: Must have at least one header to import
        at java.base/java.util.concurrent.CompletableFuture.encodeRelay(CompletableFuture.java:368)
        at java.base/java.util.concurrent.CompletableFuture.completeRelay(CompletableFuture.java:377)
        at java.base/java.util.concurrent.CompletableFuture$UniRelay.tryFire(CompletableFuture.java:1097)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162)
        at org.hyperledger.besu.services.pipeline.Pipeline.abort(Pipeline.java:180)
        at org.hyperledger.besu.services.pipeline.Pipeline.lambda$runWithErrorHandling$3(Pipeline.java:159)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.RuntimeException: Async operation failed. java.lang.IllegalArgumentException: Must have at least one header to import
        at org.hyperledger.besu.services.pipeline.AsyncOperationProcessor.outputNextCompletedTask(AsyncOperationProcessor.java:86)
        at org.hyperledger.besu.services.pipeline.AsyncOperationProcessor.attemptFinalization(AsyncOperationProcessor.java:70)
        at org.hyperledger.besu.services.pipeline.ProcessingStage.run(ProcessingStage.java:43)
        at org.hyperledger.besu.services.pipeline.Pipeline.lambda$runWithErrorHandling$3(Pipeline.java:152)
        ... 5 more
Caused by: java.util.concurrent.ExecutionException: java.lang.IllegalArgumentException: Must have at least one header to import
        at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
        at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2096)
        at org.hyperledger.besu.services.pipeline.AsyncOperationProcessor.waitForAnyFutureToComplete(AsyncOperationProcessor.java:94)
        at org.hyperledger.besu.services.pipeline.AsyncOperationProcessor.outputNextCompletedTask(AsyncOperationProcessor.java:81)
        ... 8 more
Caused by: java.lang.IllegalArgumentException: Must have at least one header to import
        at com.google.common.base.Preconditions.checkArgument(Preconditions.java:145)
        at org.hyperledger.besu.ethereum.eth.sync.range.RangeHeaders.<init>(RangeHeaders.java:39)
        at org.hyperledger.besu.ethereum.eth.sync.DownloadHeadersStep.processHeaders(DownloadHeadersStep.java:118)
        at org.hyperledger.besu.ethereum.eth.sync.DownloadHeadersStep.lambda$apply$0(DownloadHeadersStep.java:69)
        at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:646)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147)
        at org.hyperledger.besu.ethereum.eth.manager.task.AbstractPeerRequestTask.lambda$executeTask$2(AbstractPeerRequestTask.java:83)
        at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863)
        at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147)
        at java.base/java.util.Optional.ifPresent(Optional.java:178)
        at org.hyperledger.besu.ethereum.eth.manager.task.AbstractPeerRequestTask.handleMessage(AbstractPeerRequestTask.java:108)
        at org.hyperledger.besu.ethereum.eth.manager.task.AbstractPeerRequestTask.lambda$executeTask$0(AbstractPeerRequestTask.java:67)
        at org.hyperledger.besu.ethereum.eth.manager.RequestManager$ResponseStream.dispatchBufferedResponses(RequestManager.java:191)
        at org.hyperledger.besu.ethereum.eth.manager.RequestManager$ResponseStream.processMessage(RequestManager.java:182)
        at org.hyperledger.besu.ethereum.eth.manager.RequestManager.lambda$dispatchResponse$0(RequestManager.java:74)
        at java.base/java.util.Optional.ifPresentOrElse(Optional.java:196)
        at org.hyperledger.besu.ethereum.eth.manager.RequestManager.dispatchResponse(RequestManager.java:73)
        at org.hyperledger.besu.ethereum.eth.manager.EthPeer.lambda$dispatch$7(EthPeer.java:371)
        at java.base/java.util.Optional.ifPresentOrElse(Optional.java:196)
        at org.hyperledger.besu.ethereum.eth.manager.EthPeer.dispatch(EthPeer.java:370)
        at org.hyperledger.besu.ethereum.eth.manager.EthPeers.dispatchMessage(EthPeers.java:139)
        at org.hyperledger.besu.ethereum.eth.manager.EthProtocolManager.processMessage(EthProtocolManager.java:275)
        at org.hyperledger.besu.ethereum.p2p.network.NetworkRunner.lambda$setupHandlers$0(NetworkRunner.java:135)
        at org.hyperledger.besu.ethereum.p2p.rlpx.connections.PeerConnectionEvents.lambda$dispatchMessage$1(PeerConnectionEvents.java:64)
        at org.hyperledger.besu.util.Subscribers.lambda$forEach$0(Subscribers.java:112)
        at java.base/java.lang.Iterable.forEach(Iterable.java:75)
        at org.hyperledger.besu.util.Subscribers.forEach(Subscribers.java:109)
        at org.hyperledger.besu.ethereum.p2p.rlpx.connections.PeerConnectionEvents.dispatchMessage(PeerConnectionEvents.java:64)
        at org.hyperledger.besu.ethereum.p2p.rlpx.connections.netty.ApiHandler.channelRead0(ApiHandler.java:99)
        at org.hyperledger.besu.ethereum.p2p.rlpx.connections.netty.ApiHandler.channelRead0(ApiHandler.java:33)
        at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
        at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327)
        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
        at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        ... 1 more

If a response to the get header P2P request only returns the header that is the start of the range we may need to trim it to an empty response, this is breaking the validation response. One client has started returning only the range header start in some circumstances (which is a valid response per spec). Because we sometimes request an overlapping header this results in an empty stream once we cut the duplicates. fixes hyperledger#3336 Signed-off-by: Danno Ferrin <danno.ferrin@gmail.com>

garyschulte added the good first issue Good for newcomers label Feb 1, 2022

pinges assigned mark-terry Feb 10, 2022

mark-terry mentioned this issue Feb 15, 2022

Altered empty header download handling. #3433

Closed

1 task

mark-terry mentioned this issue Mar 11, 2022

Added debug logging. #3568

Merged

1 task

iamhsk closed this as completed May 5, 2022

macfarla reopened this May 11, 2022

iamhsk added the TeamChupa GH issues worked on by Chupacabara Team label Jul 14, 2022

fab-10 mentioned this issue Jul 28, 2022

Accept empty header set in range headers validation #4189

Merged

2 tasks

shemnon closed this as completed in 962c805 Jul 28, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

IllegalArgumentException: Must have at least one header to import #3336

IllegalArgumentException: Must have at least one header to import #3336

fab-10 commented Jan 27, 2022

frankisawesome commented Mar 8, 2022

iamhsk commented Apr 28, 2022

macfarla commented May 11, 2022

kirillp commented May 12, 2022

xrchz commented Jul 13, 2022

ibhagwan commented Jul 22, 2022

IllegalArgumentException: Must have at least one header to import #3336

IllegalArgumentException: Must have at least one header to import #3336

Comments

fab-10 commented Jan 27, 2022

Description

Versions (Add all that apply)

frankisawesome commented Mar 8, 2022

iamhsk commented Apr 28, 2022

macfarla commented May 11, 2022

kirillp commented May 12, 2022

xrchz commented Jul 13, 2022

ibhagwan commented Jul 22, 2022