Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[KC17] Frequent "Unexpected server error" mostly without any log #10892

Closed
semangard opened this issue Mar 23, 2022 · 10 comments
Closed

[KC17] Frequent "Unexpected server error" mostly without any log #10892

semangard opened this issue Mar 23, 2022 · 10 comments
Labels
area/dist/quarkus kind/bug Categorizes a PR related to a bug status/triage

Comments

@semangard
Copy link

semangard commented Mar 23, 2022

Describe the bug

Hello,

I migrated from KC16 to KC17 on my local dev PC (quarkus) => DB migrated at KC17 startup.
I run KC17 as a Docker container.
I noticed I have frequently errors like: unexpected server error

image

AND there isn't any WARN or ERROR into the console logs.

I do not know where it could come from...

Version

17.0.0

Expected behavior

Correctly trap errors to be able to undertsand them and investigate further.

Actual behavior

Frequent "Unexpected server error" without any log

How to Reproduce?

No response

Anything else?

One time I got the stack trace:

keycloak17     | 2022-03-23 13:10:41,950 ERROR [org.jboss.threads.errors] (executor-thread-6) Thread Thread[executor-thread-6,5,main] threw an uncaught exception: java.lang.RuntimeException: java.io.IOException: java.io.IOException: io.netty.handler.codec.http2.Http2Exception$StreamException: Stream closed before write could take place
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxHttpRequest$VertxExecutionContext$VertxHttpAsyncResponse.vertxFlush(VertxHttpRequest.java:396)
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxHttpRequest$VertxExecutionContext$VertxHttpAsyncResponse$1.run(VertxHttpRequest.java:326)
keycloak17     |        at io.quarkus.vertx.core.runtime.VertxCoreRecorder$13.runWith(VertxCoreRecorder.java:543)
keycloak17     |        at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
keycloak17     |        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1478)
keycloak17     |        at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
keycloak17     |        at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
keycloak17     |        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
keycloak17     |        at java.base/java.lang.Thread.run(Thread.java:829)
keycloak17     | Caused by: java.io.IOException: java.io.IOException: io.netty.handler.codec.http2.Http2Exception$StreamException: Stream closed before write could take place
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxOutputStream.close(VertxOutputStream.java:128)
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxHttpResponse.finish(VertxHttpResponse.java:145)
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxHttpRequest$VertxExecutionContext$VertxHttpAsyncResponse.vertxFlush(VertxHttpRequest.java:394)
keycloak17     |        ... 8 more
keycloak17     | Caused by: java.io.IOException: io.netty.handler.codec.http2.Http2Exception$StreamException: Stream closed before write could take place
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxBlockingOutput.write(VertxBlockingOutput.java:74)
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxHttpResponse.writeBlocking(VertxHttpResponse.java:172)
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxOutputStream.close(VertxOutputStream.java:126)
keycloak17     |        ... 10 more
keycloak17     | Caused by: io.netty.handler.codec.http2.Http2Exception$StreamException: Stream closed before write could take place
keycloak17     |        at io.netty.handler.codec.http2.Http2Exception.streamError(Http2Exception.java:172)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2RemoteFlowController$FlowState.cancel(DefaultHttp2RemoteFlowController.java:481)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2RemoteFlowController$1.onStreamClosed(DefaultHttp2RemoteFlowController.java:105)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2Connection.notifyClosed(DefaultHttp2Connection.java:357)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2Connection$ActiveStreams.removeFromActiveStreams(DefaultHttp2Connection.java:1007)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2Connection$ActiveStreams.deactivate(DefaultHttp2Connection.java:963)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2Connection$DefaultStream.close(DefaultHttp2Connection.java:515)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2Connection.close(DefaultHttp2Connection.java:153)
keycloak17     |        at io.netty.handler.codec.http2.Http2ConnectionHandler$BaseDecoder.channelInactive(Http2ConnectionHandler.java:209)
keycloak17     |        at io.netty.handler.codec.http2.Http2ConnectionHandler.channelInactive(Http2ConnectionHandler.java:417)
keycloak17     |        at io.vertx.core.http.impl.VertxHttp2ConnectionHandler.channelInactive(VertxHttp2ConnectionHandler.java:127)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241)
keycloak17     |        at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81)
keycloak17     |        at io.netty.handler.timeout.IdleStateHandler.channelInactive(IdleStateHandler.java:277)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241)
keycloak17     |        at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:392)
keycloak17     |        at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:357)
keycloak17     |        at io.netty.handler.ssl.SslHandler.channelInactive(SslHandler.java:1073)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241)
keycloak17     |        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
keycloak17     |        at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901)
keycloak17     |        at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:813)
keycloak17     |        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
keycloak17     |        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
keycloak17     |        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
keycloak17     |        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
keycloak17     |        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
keycloak17     |        ... 2 more

or this one :

keycloak17     | 2022-03-23 09:21:51,896 ERROR [org.keycloak.services.error.KeycloakErrorHandler] (executor-thread-1) Uncaught server error: java.lang.RuntimeException: java.io.IOException: java.io.IOException: java.nio.channels.ClosedChannelException
keycloak17     |        at org.jboss.resteasy.plugins.server.BaseHttpRequest.getFormParameters(BaseHttpRequest.java:61)
keycloak17     |        at org.jboss.resteasy.plugins.server.BaseHttpRequest.getDecodedFormParameters(BaseHttpRequest.java:74)
keycloak17     |        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
keycloak17     |        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
keycloak17     |        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
keycloak17     |        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
keycloak17     |        at org.jboss.resteasy.core.ContextParameterInjector$GenericDelegatingProxy.invoke(ContextParameterInjector.java:166)
keycloak17     |        at com.sun.proxy.$Proxy46.getDecodedFormParameters(Unknown Source)
keycloak17     |        at org.keycloak.protocol.oidc.endpoints.TokenEndpoint.processGrantRequest(TokenEndpoint.java:169)
keycloak17     |        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
keycloak17     |        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
keycloak17     |        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
keycloak17     |        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
keycloak17     |        at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:170)
keycloak17     |        at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
keycloak17     |        at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:660)
keycloak17     |        at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:524)
keycloak17     |        at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:474)
keycloak17     |        at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
keycloak17     |        at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:476)
keycloak17     |        at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:434)
keycloak17     |        at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:192)
keycloak17     |        at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
keycloak17     |        at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
keycloak17     |        at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:141)
keycloak17     |        at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:32)
keycloak17     |        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:492)
keycloak17     |        at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:261)
keycloak17     |        at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:161)
keycloak17     |        at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
keycloak17     |        at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:164)
keycloak17     |        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:247)
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:151)
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:82)
keycloak17     |        at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:42)
keycloak17     |        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
keycloak17     |        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
keycloak17     |        at io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:201)
keycloak17     |        at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:67)
keycloak17     |        at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:55)
keycloak17     |        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
keycloak17     |        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
keycloak17     |        at io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:201)
keycloak17     |        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:362)
keycloak17     |        at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:340)
keycloak17     |        at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
keycloak17     |        at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
keycloak17     |        at io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:201)
keycloak17     |        at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$1(QuarkusRequestFilter.java:66)
keycloak17     |        at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
keycloak17     |        at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
keycloak17     |        at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
keycloak17     |        at io.quarkus.vertx.core.runtime.VertxCoreRecorder$13.runWith(VertxCoreRecorder.java:543)
keycloak17     |        at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
keycloak17     |        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1452)
keycloak17     |        at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
keycloak17     |        at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
keycloak17     |        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
keycloak17     |        at java.base/java.lang.Thread.run(Thread.java:829)
keycloak17     | Caused by: java.io.IOException: java.io.IOException: java.nio.channels.ClosedChannelException
keycloak17     |        at io.quarkus.vertx.http.runtime.VertxInputStream$VertxBlockingInput.readBlocking(VertxInputStream.java:254)
keycloak17     |        at io.quarkus.vertx.http.runtime.VertxInputStream.readIntoBuffer(VertxInputStream.java:121)
keycloak17     |        at io.quarkus.vertx.http.runtime.VertxInputStream.read(VertxInputStream.java:83)
keycloak17     |        at java.base/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
keycloak17     |        at java.base/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
keycloak17     |        at java.base/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
keycloak17     |        at java.base/java.io.InputStreamReader.read(InputStreamReader.java:181)
keycloak17     |        at java.base/java.io.BufferedReader.fill(BufferedReader.java:161)
keycloak17     |        at java.base/java.io.BufferedReader.read1(BufferedReader.java:212)
keycloak17     |        at java.base/java.io.BufferedReader.read(BufferedReader.java:287)
keycloak17     |        at org.jboss.resteasy.plugins.providers.FormUrlEncodedProvider.parseForm(FormUrlEncodedProvider.java:88)
keycloak17     |        at org.jboss.resteasy.plugins.server.BaseHttpRequest.getFormParameters(BaseHttpRequest.java:57)
keycloak17     |        ... 59 more
keycloak17     | Caused by: java.io.IOException: java.nio.channels.ClosedChannelException
keycloak17     |        at io.quarkus.vertx.http.runtime.VertxInputStream$VertxBlockingInput$2.handle(VertxInputStream.java:201)
keycloak17     |        at io.quarkus.vertx.http.runtime.VertxInputStream$VertxBlockingInput$2.handle(VertxInputStream.java:197)
keycloak17     |        at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
keycloak17     |        at io.vertx.core.http.impl.HttpEventHandler.handleException(HttpEventHandler.java:89)
keycloak17     |        at io.vertx.core.http.impl.Http2ServerRequest.notifyException(Http2ServerRequest.java:148)
keycloak17     |        at io.vertx.core.http.impl.Http2ServerRequest.handleClose(Http2ServerRequest.java:181)
keycloak17     |        at io.vertx.core.http.impl.VertxHttp2Stream.lambda$onClose$2(VertxHttp2Stream.java:85)
keycloak17     |        at io.vertx.core.impl.EventLoopContext.execute(EventLoopContext.java:71)
keycloak17     |        at io.vertx.core.impl.DuplicatedContext.execute(DuplicatedContext.java:163)
keycloak17     |        at io.vertx.core.impl.AbstractContext.execute(AbstractContext.java:58)
keycloak17     |        at io.vertx.core.http.impl.VertxHttp2Stream.onClose(VertxHttp2Stream.java:85)
keycloak17     |        at io.vertx.core.http.impl.Http2ServerRequest.onClose(Http2ServerRequest.java:170)
keycloak17     |        at io.vertx.core.http.impl.Http2ConnectionBase.onStreamClosed(Http2ConnectionBase.java:148)
keycloak17     |        at io.vertx.core.http.impl.VertxHttp2ConnectionHandler.onStreamClosed(VertxHttp2ConnectionHandler.java:163)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2Connection.notifyClosed(DefaultHttp2Connection.java:357)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2Connection$ActiveStreams.removeFromActiveStreams(DefaultHttp2Connection.java:1007)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2Connection$ActiveStreams.deactivate(DefaultHttp2Connection.java:963)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2Connection$DefaultStream.close(DefaultHttp2Connection.java:515)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2Connection$DefaultStream.close(DefaultHttp2Connection.java:521)
keycloak17     |        at io.netty.handler.codec.http2.Http2ConnectionHandler.closeStream(Http2ConnectionHandler.java:613)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onRstStreamRead(DefaultHttp2ConnectionDecoder.java:444)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readRstStreamFrame(DefaultHttp2FrameReader.java:509)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:259)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:159)
keycloak17     |        at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:173)
keycloak17     |        at io.netty.handler.codec.http2.DecoratingHttp2ConnectionDecoder.decodeFrame(DecoratingHttp2ConnectionDecoder.java:63)
keycloak17     |        at io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:378)
keycloak17     |        at io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:438)
keycloak17     |        at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:510)
keycloak17     |        at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:449)
keycloak17     |        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:279)
keycloak17     |        at io.vertx.core.http.impl.VertxHttp2ConnectionHandler.channelRead(VertxHttp2ConnectionHandler.java:378)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
keycloak17     |        at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
keycloak17     |        at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1371)
keycloak17     |        at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1234)
keycloak17     |        at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1283)
keycloak17     |        at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:510)
keycloak17     |        at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:449)
keycloak17     |        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:279)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
keycloak17     |        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
keycloak17     |        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
keycloak17     |        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
keycloak17     |        at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
keycloak17     |        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722)
keycloak17     |        at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:623)
keycloak17     |        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:586)
keycloak17     |        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496)
keycloak17     |        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
keycloak17     |        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
keycloak17     |        ... 2 more
keycloak17     | Caused by: java.nio.channels.ClosedChannelException
keycloak17     |        ... 56 more

@semangard semangard added kind/bug Categorizes a PR related to a bug status/triage labels Mar 23, 2022
@semangard semangard changed the title [KC17] Frequent "Unexpected server error" without any log [KC17] Frequent "Unexpected server error" mostly without any log Mar 23, 2022
@HarunOr
Copy link

HarunOr commented Mar 24, 2022

I had the same issue, removing the old container and rebuilding it fixed it for me.

@semangard
Copy link
Author

Yes but it comes back...

@HarunOr
Copy link

HarunOr commented Mar 24, 2022

Have you checked your environment variables or commands? Some of them changed.

https://www.keycloak.org/server/all-config

@semangard
Copy link
Author

yes, yes :-)

version: '3.8'

#### DOCS ####
# https://github.com/eabykov/keycloak-compose/blob/main/docker-compose.yml
# https://blog.codecentric.de/en/2021/12/keycloak-keycloak-x/
##############

services:
  
  postgres:
    container_name: keycloak17-db
    image: postgres:13.2-alpine
    environment:
      POSTGRES_DB: keycloak
      POSTGRES_USER: keycloak
      POSTGRES_PASSWORD: password
    volumes:
    - keycloak17_postgres_data:/var/lib/postgresql/data
    networks:
    - network-development
    ports:
     - "5432:5432"

  keycloak:
    container_name: keycloak17
    image: quay.io/keycloak/keycloak:17.0.1
    environment:
      KEYCLOAK_ADMIN: admin
      KEYCLOAK_ADMIN_PASSWORD: admin
      
      ## https://www.keycloak.org/server/db
      ## https://www.keycloak.org/server/all-config#_database
      KC_DB: postgres
      KC_DB_URL: "jdbc:postgresql://postgres:5432/keycloak"  # jdbc:postgresql://host:port/database
      KC_DB_USERNAME: keycloak
      KC_DB_PASSWORD: password
      
      ## https://www.keycloak.org/server/hostname
      KC_HOSTNAME: localhost # mandatory because we are using the production mode (launch with 'start' and not 'start-dev') better to be as closed as possible to the production
      # KC_HOSTNAME_ADMIN: localhost
      # KC_HOSTNAME_STRICT_BACKCHANNEL: true
      KC_HTTP_RELATIVE_PATH: "/auth" # mandatory to keep same URL compared to previous versions of KC
      
      ## https://www.keycloak.org/server/enabletls
      ## https://www.keycloak.org/server/all-config#_httptls
      KC_HTTP_ENABLED: "true"
      KC_HOSTNAME_STRICT_HTTPS: "false" # because issue https://github.com/keycloak/keycloak/issues/10899#issuecomment-1077412928
      KC_HTTPS_PROTOCOLS: "TLSv1.3,TLSv1.2"
      #KC_HTTPS_CIPER_SUITES: ### TODO
      KC_HTTPS_CERTIFICATE_FILE: "/etc/x509/https/tls.crt"
      KC_HTTPS_CERTIFICATE_KEY_FILE: "/etc/x509/https/tls.key"
      KC_HTTPS_TRUST_STORE_FILE: "/etc/x509/https/hugkeystore"
      KC_HTTPS_TRUST_STORE_PASSWORD: keycloak

      ## https://www.keycloak.org/server/all-config#_feature
      ## https://www.keycloak.org/server/features
      KC_FEATURES: admin-fine-grained-authz,token-exchange,upload-scripts
      
      JAVA_TOOL_OPTIONS: -Dsun.security.krb5.debug=true -Dsun.security.spenego.degug=true -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=8790 -Dcom.sun.management.jmxremote.local.only=false -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Dquarkus-log-max-startup-records=10000
      JAVA_OPTS: -server -Xms512m -Xmx2048m -XX:MetaspaceSize=96M -XX:MaxMetaspaceSize=256m -Djava.awt.headless=true -Djava.net.preferIPv4Stack=true # JAVA_OPTS_APPEND does not work
           
      ## https://www.keycloak.org/server/all-config#_cluster
      ## https://www.keycloak.org/server/caching
      ## https://github.com/keycloak/keycloak/issues/10780
      ## https://github.com/keycloak/keycloak/issues/10875
      # JGROUPS_DISCOVERY_PROTOCOL: JDBC_PING   ### DEPRECATED
      # JGROUPS_DISCOVERY_PROPERTIES: datasource_jndi_name=java:jboss/datasources/KeycloakDS,info_writer_sleep_time=500,remove_old_coords_on_view_change=true,remove_all_data_on_view_change=true  ### DEPRECATED
      # CACHE_OWNERS_COUNT: 1  ### DEPRECATED => useless now ?
      # CACHE_OWNERS_AUTH_SESSIONS_COUNT: 1 ### DEPRECATED => useless now ?
      # ... to be tested with a cluster ...
      KC_CACHE: ispn
      KC_CACHE_STACK: tcp
      
      ## https://www.keycloak.org/server/logging
      ## https://www.keycloak.org/server/all-config#_logging
      KC_LOG_LEVEL: INFO     
      
      ## https://www.keycloak.org/server/all-config#_metrics
      KC_METRICS_ENABLED: true # https://localhost/auth/metrics
      # KEYCLOAK_STATISTICS: all ### DEPRECATED: no solution yet

      # DEBUG: true
      # DEBUG_PORT: "*:8787"
      
      # DISABLE UI CACHE
      # https://github.com/keycloak/keycloak/issues/10863
      SPI_THEME_CACHE_THEMES: false
      SPI_THEME_CACHE_TEMPLATES: false
      SPI_THEME_STATIC_MAX_AGE: -1
      
      # https://github.com/keycloak/keycloak/discussions/10229
      KEYCLOAK_IMPORT: /tmp/keycloak/config/realm.json # cf also temporary fix script which does not event work...  ### TODO : will be available with KC 17.0.1 ?
      
      ## CUSTOM for HUG listener
      USER_EVENT_TO_SEND: CREATE,UPDATE,DELETE,LOGIN
      KEYCLOAK_SERVICE_URL: http://keycloak-service:10001/
    ###########################
    ## WARNING :  --auto-build has to be used for dev purpose, for perf concern (quick start-up) ==> build your own custom image
    # a) CUSTOM entrypoint to enable realm import : https://github.com/keycloak/keycloak/discussions/10229   ==> Does NOT / CANNOT WORK with a DB: driver is not yet initialized
    # entrypoint: ["/tmp/keycloak/config/docker-compose-entrypoint.sh", "start", "--auto-build"]
    # b) STANDARD enrtrypoint
    entrypoint: ["/opt/keycloak/bin/kc.sh", "start", "--auto-build"]
    volumes:
    ###########################
    # Import test realm
    - ./scripts:/tmp/keycloak/config
    - ./realms/realm.json:/tmp/keycloak/config/realm.json:ro
    ###########################
    # HUG themes and extensions
    - ../../theme/hug-base:/opt/keycloak/themes/hug-base
    - ../../theme/hug-hug:/opt/keycloak/themes/hug-hug
    - ../../theme/pedamines-base:/opt/keycloak/themes/pedamines-base # TODO: to be remamed as external-base
    # HUG extensions
    - ../../target/hug-keycloak-jar-with-dependencies.jar:/opt/keycloak/providers/hug-keycloak.jar:ro
    # HUG passwords blacklists
    - ../../blacklists/french_passwords_top20000.txt:/opt/data/password-blacklists/french_passwords_top20000.txt:ro
    - ../../blacklists/hug_pwd_blacklist_2021.txt:/opt/data/password-blacklists/hug_pwd_blacklist_2021.txt:ro
    # External extensions
    - ../../extensions/metrics/keycloak-metrics-spi-2.5.3.jar:/opt/keycloak/providers/keycloak-metrics-spi-2.5.3.jar:ro
    - ../../extensions/france-connect/keycloak-franceconnect-4.1.0.jar:/opt/keycloak/providers/keycloak-franceconnect-4.1.0.jar:ro
    # Custom configurations with CLI 
    # - ../../cli/logs-manage.cli:/opt/startup-scripts/logs-manage.cli ### DEPRECATED => TODO: find a solution to send logs to logstash
    # - ../../cli/logs-http-debug.cli:/opt/startup-scripts/logs-http-debug.cli ### DEPRECATED => TODO: any solution ? (optional)
    ################
    # Self-signed certificates to activate HTTPS for tests
    - ./certs/server/server.tls.crt:/etc/x509/https/tls.crt:ro
    - ./certs/server/server.tls.key:/etc/x509/https/tls.key:ro
    ## DEPRECATED, replace by imporzing keystore
    # CA certificates to enable user auth with certificates (choose the one(s) you want to use)
    # - ./certs/ca.crt:/etc/x509/https/rootCA.crt:ro # auto-signed CA cert
    # - ./certs/hugca.crt:/etc/x509/https/hugrootCA.crt:ro # HUG CA cert
    - ./certs/hugkeystore:/etc/x509/https/hugkeystore:ro 
    ################
    ports:
    - "8080:8080" # KC HTTP  : http://localhost:8080/
    - "443:8443"  # KC HTTPS : https://localhost/ (you must accept also warnings triggered by navigators)
    - "8787:8787" # KC debug port
    - "8790:8790" # KC JMX port
    deploy:
      replicas: 1
    depends_on:
    - postgres
    networks:
    - network-development

networks:
  network-development:

volumes:
  keycloak17_postgres_data:
    external: true # because the volume was clone from keycloak 13 DB (in order to test separately the migration)
    # driver: local

@HarunOr
Copy link

HarunOr commented Mar 24, 2022

Which docker-compose version are you using?
I am using version v2.3.3 and my env variables don't have quotation marks.

Maybe try removing them? I think in some cases docker copied the env vars with the quotation marks.

I am just guessing here though.

@semangard
Copy link
Author

I am using latest version of Docker Desktop for Windows.

image

@DGuhr
Copy link
Contributor

DGuhr commented Mar 29, 2022

@pedroigor could this perhaps also be solved by #10917 ? Just guessing here, as it seems to be resteasy related. I never experienced this error, and could not reproduce.

@pedroigor
Copy link
Contributor

Not sure. @semangard Can you please tell us when that happens? If during authentication, accessing the admin/account console, etc?

@semangard
Copy link
Author

Hello @pedroigor
it happened just after having migrated from v16 to v17 (quarkus).
I got this error sporadically on various screens and most often without any errors into the logs.

@pedroigor
Copy link
Contributor

pedroigor commented Jun 14, 2022

Thanks. It should be fixed already because we had some fixes related to a similar problem:

If the issue still persists, please re-open.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/dist/quarkus kind/bug Categorizes a PR related to a bug status/triage
Projects
None yet
Development

No branches or pull requests

4 participants