search

Consensys / teku

Open-source Ethereum consensus client written in Java
https://consensys.io/teku
Apache License 2.0
665 stars 283 forks source link

Clean up stack traces when execution client is not available #7464

Closed benjaminion closed 1 year ago

benjaminion commented 1 year ago

I started Besu and Teku at the same time. While Besu was starting Teku dumped ugly stack traces. It would be much more friendly to see a one line error or warning message in these circumstances.

2023-08-28 07:57:10.319 WARN  - Not loading specified initial state as chain data already exists.
2023-08-28 07:57:10.326 WARN  - Rest API is enabled but no default fee recipient has been configured via the validators-proposer-default-fee-recipient option! It is strongly recommended to configure it to avoid po>
2023-08-28 07:57:11.369 INFO  - BLS: loaded BLST library
2023-08-28 07:57:16.422 INFO  - Completed regeneration of state for block 0xf45ffefc077f61c5dff18f8ef9351577027031604744068124f848c645179891 at slot 7198720 by replaying 32 blocks. Took 6078ms
2023-08-28 07:57:16.605 ERROR - Execution Client request failed. Make sure the Execution Client is online and can respond to requests.
java.net.ConnectException: Failed to connect to /127.0.0.1:8551
at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.kt:297) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.connection.RealConnection.connect(RealConnection.kt:207) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.connection.ExchangeFinder.findConnection(ExchangeFinder.kt:226) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.connection.ExchangeFinder.findHealthyConnection(ExchangeFinder.kt:106) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.connection.ExchangeFinder.find(ExchangeFinder.kt:74) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.connection.RealCall.initExchange$okhttp(RealCall.kt:255) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:32) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[okhttp-4.11.0.jar:?]
at tech.pegasys.teku.ethereum.executionclient.auth.JwtAuthHttpInterceptor.intercept(JwtAuthHttpInterceptor.java:41) ~[teku-ethereum-executionclient-23.8.0.jar:23.8.0]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.connection.RealCall.execute(RealCall.kt:154) ~[okhttp-4.11.0.jar:?]
at org.web3j.protocol.http.HttpService.performIO(HttpService.java:159) ~[core-4.10.1.jar:?]
at org.web3j.protocol.Service.send(Service.java:48) ~[core-4.10.1.jar:?]
at org.web3j.protocol.Service.lambda$sendAsync$0(Service.java:60) ~[core-4.10.1.jar:?]
at org.web3j.utils.Async.lambda$run$1(Async.java:38) ~[core-4.10.1.jar:?]
at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:833) [?:?]
Caused by: java.net.ConnectException: Connection refused
at sun.nio.ch.Net.pollConnect(Native Method) ~[?:?]
at sun.nio.ch.Net.pollConnectNow(Net.java:672) ~[?:?]
at sun.nio.ch.NioSocketImpl.timedFinishConnect(NioSocketImpl.java:547) ~[?:?]
at sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:602) ~[?:?]
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327) ~[?:?]
at java.net.Socket.connect(Socket.java:633) ~[?:?]
at okhttp3.internal.platform.Platform.connectSocket(Platform.kt:128) ~[okhttp-4.11.0.jar:?]
at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.kt:295) ~[okhttp-4.11.0.jar:?]
... 25 more
2023-08-28 07:57:16.611 ERROR - Failed to update fork choice
java.util.concurrent.CompletionException: tech.pegasys.teku.ethereum.executionclient.response.InvalidRemoteResponseException: Invalid remote response from the execution client: Failed to connect to /127.0.0.1:8551
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:315) ~[?:?]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:320) ~[?:?]
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:649) ~[?:?]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?]
at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147) ~[?:?]
at tech.pegasys.teku.infrastructure.async.SafeFuture.lambda$propagateResult$3(SafeFuture.java:148) ~[teku-infrastructure-async-23.8.0.jar:23.8.0]
at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) ~[?:?]
at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) ~[?:?]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?]
at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147) ~[?:?]
at tech.pegasys.teku.infrastructure.async.SafeFuture.lambda$propagateResult$3(SafeFuture.java:148) ~[teku-infrastructure-async-23.8.0.jar:23.8.0]
at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) ~[?:?]
at java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:887) ~[?:?]
at java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2325) ~[?:?]
at tech.pegasys.teku.infrastructure.async.SafeFuture.whenComplete(SafeFuture.java:626) ~[teku-infrastructure-async-23.8.0.jar:23.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.whenComplete(SafeFuture.java:33) ~[teku-infrastructure-async-23.8.0.jar:23.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.propagateResult(SafeFuture.java:143) ~[teku-infrastructure-async-23.8.0.jar:23.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.lambda$exceptionallyCompose$34(SafeFuture.java:426) ~[teku-infrastructure-async-23.8.0.jar:23.8.0]
at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) ~[?:?]
at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) ~[?:?]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162) ~[?:?]
at tech.pegasys.teku.infrastructure.async.SafeFuture.lambda$propagateResult$3(SafeFuture.java:146) ~[teku-infrastructure-async-23.8.0.jar:23.8.0]
at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) ~[?:?]
at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) ~[?:?]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162) ~[?:?]
at org.web3j.utils.Async.lambda$run$1(Async.java:40) ~[core-4.10.1.jar:?]
at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:833) [?:?]
Caused by: tech.pegasys.teku.ethereum.executionclient.response.InvalidRemoteResponseException: Invalid remote response from the execution client: Failed to connect to /127.0.0.1:8551
at tech.pegasys.teku.ethereum.executionclient.response.ResponseUnwrapper.unwrapResponseOrThrow(ResponseUnwrapper.java:34) ~[teku-ethereum-executionclient-23.8.0.jar:23.8.0]
at tech.pegasys.teku.ethereum.executionclient.response.ResponseUnwrapper.unwrapExecutionClientResponseOrThrow(ResponseUnwrapper.java:21) ~[teku-ethereum-executionclient-23.8.0.jar:23.8.0]
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:646) ~[?:?]
... 29 more

Versions (Add all that apply)

tbenr commented 1 year ago

another one is:

2023-08-29 11:45:46.033 ERROR - Validator   *** Failed to send validator registrations to the builder network via the Beacon Node
java.util.concurrent.CompletionException: java.lang.IllegalStateException: Couldn't retrieve validator statuses during registering. Most likely the BN is still syncing.
at java.util.concurrent.CompletableFuture.encodeRelay(CompletableFuture.java:368) ~[?:?]
at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1189) ~[?:?]
at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) ~[?:?]
at tech.pegasys.teku.infrastructure.async.SafeFuture.thenCompose(SafeFuture.java:548) ~[classes/:?]
at tech.pegasys.teku.validator.coordinator.ValidatorApiHandler.registerValidators(ValidatorApiHandler.java:640) ~[classes/:?]
at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:577) ~[?:?]
at tech.pegasys.teku.infrastructure.events.DirectEventDeliverer.executeMethod(DirectEventDeliverer.java:74) ~[classes/:?]
at tech.pegasys.teku.infrastructure.events.DirectEventDeliverer.deliverToWithResponse(DirectEventDeliverer.java:67) ~[classes/:?]
at tech.pegasys.teku.infrastructure.events.AsyncEventDeliverer.lambda$deliverToWithResponse$1(AsyncEventDeliverer.java:80) ~[classes/:?]
at tech.pegasys.teku.infrastructure.events.AsyncEventDeliverer$QueueReader.deliverNextEvent(AsyncEventDeliverer.java:125) ~[classes/:?]
at tech.pegasys.teku.infrastructure.events.AsyncEventDeliverer$QueueReader.run(AsyncEventDeliverer.java:116) ~[classes/:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:833) [?:?]
Caused by: java.lang.IllegalStateException: Couldn't retrieve validator statuses during registering. Most likely the BN is still syncing.
at tech.pegasys.teku.validator.coordinator.ValidatorApiHandler.lambda$registerValidators$30(ValidatorApiHandler.java:645) ~[classes/:?]
at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) ~[?:?]
... 13 more

happening at startup when there are validators to be registered against builder network.