ERROR - Failed to process event queue for client

[benjaminion]

Reported by user Torran on Discord.

I got a random error in my Teku logs, didn't seem to affect its operation, should I be concerned?

ERROR - Failed to process event queue for client 902268355
java.util.concurrent.CompletionException: java.lang.IllegalStateException: s=OPEN,api=BLOCKED,sc=false,e=null
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:332) ~[?:?]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:347) ~[?:?]
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:636) ~[?:?]
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:145) ~[teku-infrastructure-async-22.8.0.jar:22.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:576) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.whenComplete(SafeFuture.java:32) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.propagateResult(SafeFuture.java:142) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.lambda$exceptionallyCompose$29(SafeFuture.java:395) ~[teku-infrastructure-async-22.8.0.jar:22.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:145) ~[teku-infrastructure-async-22.8.0.jar:22.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:576) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.whenComplete(SafeFuture.java:32) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.propagateResult(SafeFuture.java:142) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.propagateTo(SafeFuture.java:289) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
at tech.pegasys.teku.infrastructure.async.ScheduledExecutorAsyncRunner.lambda$createRunnableForAction$1(ScheduledExecutorAsyncRunner.java:119) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
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: s=OPEN,api=BLOCKED,sc=false,e=null
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:828) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.HttpOutput.print(HttpOutput.java:1139) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.HttpOutput.print(HttpOutput.java:1068) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at io.javalin.http.sse.Emitter.emit(Emitter.kt:29) ~[javalin-4.6.4.jar:4.6.4]
at io.javalin.http.sse.SseClient.sendEvent(SseClient.kt:29) ~[javalin-4.6.4.jar:4.6.4]
Aug 15 14:13:19 eth-node teku[407600]: at io.javalin.http.sse.SseClient.sendEvent$default(SseClient.kt:27) ~[javalin-4.6.4.jar:4.6.4]
at io.javalin.http.sse.SseClient.sendEvent(SseClient.kt) ~[javalin-4.6.4.jar:4.6.4]
at tech.pegasys.teku.beaconrestapi.handlers.v1.events.EventSubscriber.lambda$processEventQueue$1(EventSubscriber.java:121) ~[teku-data-beaconrestapi-22.8.0.jar:22.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.fromRunnable(SafeFuture.java:154) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
at tech.pegasys.teku.infrastructure.async.AsyncRunner.lambda$runAsync$0(AsyncRunner.java:23) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
at tech.pegasys.teku.infrastructure.async.SafeFuture.of(SafeFuture.java:73) ~[teku-infrastructure-async-22.8.0.jar:22.8.0]
... 4 more

[torran-g]

More details

• Teku v22.8.0
• EL: Besu v22.7.0
• Network: Mainnet
• Synced but no activated validators.

[ajsutton]

This error is saying that the Teku beacon node couldn't send an event to some client connected to the /eth/v1/events endpoint. I'm not entirely sure I understand the situation but it looks like the socket was unable to be written to fast enough - though it does look suspiciously like a bug in the underlying jetty HTTP library since it typically should have blocked until it could write and IllegalStateException is definitely something I wouldn't expect it to throw...

Were you running a separate validator client or would something else have been subscribed to the events endpoint? If it wasn't an external VC, what events was it subscribed to?

[torran-g]

I'm not running a separate VC. Unsure what would be subscribed to it, the only thing I can think of is the ethereum-metrics-exporter but I don't see anything related in its logs.

[ajsutton]

ah, yeah ethereum-metrics-exporter hits the event stream pretty hard. There's a good chance it wasn't able to read the data being sent fast enough. Teku should handle this gracefully and disconnect it without the error but hopefully that gives us something to go on to try and reproduce this.

[ajsutton]

We've now updated Jetty and I'm no longer able to reproduce this.