keycloak-webhook icon indicating copy to clipboard operation
keycloak-webhook copied to clipboard
verified publisher icon vymalo

AMQP plugin loses connection to RabbitMQ

Open schreiberstein opened this issue 6 months ago • 6 comments

Greetings,

first of, thank you very much for the creation of this plugin and your continued efforts.

I am currently experiencing issues when the plugin is active, causing Keycloak to throw error 500 to user requests due to the plugin losing its connection to the upstream RabbitMQ server.

Setup:

  • Debian GNU/Linux Docker host (amd64)
  • Keycloak 26.2
  • RabbitMQ 4.1 (direct AMQP connection, no SSL)
  • Plugin version 0.9.1 (latest available binary)
  • Both containers run on the same host, in the same docker-compose stack, in the same network (= no networking issues, no firewall)

After a couple of requests, I receive the following stack traces in the Keycloack Docker log (the client application receives HTTP code 500).

Error: 2025-06-18 12:58:30,036 ERROR [org.keycloak.services.error.KeycloakErrorHandler] (executor-thread-301) Uncaught server error: java.io.IOException at com.rabbitmq.client.impl.AMQChannel.wrap(AMQChannel.java:140) at com.rabbitmq.client.impl.AMQChannel.wrap(AMQChannel.java:136) at com.rabbitmq.client.impl.AMQChannel.exnWrappingRpc(AMQChannel.java:158) at com.rabbitmq.client.impl.ChannelN.open(ChannelN.java:136) at com.rabbitmq.client.impl.ChannelManager.createChannel(ChannelManager.java:189) at com.rabbitmq.client.impl.AMQConnection.createChannel(AMQConnection.java:638) at com.rabbitmq.client.impl.recovery.AutorecoveringConnection.createChannel(AutorecoveringConnection.java:174) at com.vymalo.keycloak.webhook.AmqpWebhookHandler.initHandler(AmqpWebhookHandler.kt:139) at com.vymalo.keycloak.webhook.AbstractWebhookEventListenerFactory.ensureParametersInit(AbstractWebhookEventListenerFactory.kt:39) at com.vymalo.keycloak.webhook.AbstractWebhookEventListenerFactory.create(AbstractWebhookEventListenerFactory.kt:32) at com.vymalo.keycloak.webhook.AbstractWebhookEventListenerFactory.create(AbstractWebhookEventListenerFactory.kt:16) at org.keycloak.services.DefaultKeycloakSession.getOrCreateProvider(DefaultKeycloakSession.java:184) at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:195) at org.keycloak.models.KeycloakBeanProducer_ProducerMethod_getKeycloakSession_XoSEUTXOsE3bpqXlGMAykCiECUM_ClientProxy.getProvider(Unknown Source) at org.keycloak.events.EventBuilder.lambda$getEventListeners$1(EventBuilder.java:94) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179) at java.base/java.util.HashMap$ValueSpliterator.forEachRemaining(HashMap.java:1787) at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:575) at java.base/java.util.stream.AbstractPipeline.evaluateToArrayNode(AbstractPipeline.java:260) at java.base/java.util.stream.ReferencePipeline.toArray(ReferencePipeline.java:616) at java.base/java.util.stream.ReferencePipeline.toArray(ReferencePipeline.java:622) at java.base/java.util.stream.ReferencePipeline.toList(ReferencePipeline.java:627) at org.keycloak.events.EventBuilder.getEventListeners(EventBuilder.java:96) at org.keycloak.events.EventBuilder.<init>(EventBuilder.java:74) at org.keycloak.events.EventBuilder.<init>(EventBuilder.java:62) at org.keycloak.services.resources.RealmsResource.getProtocol(RealmsResource.java:117) at org.keycloak.services.resources.RealmsResource$quarkusrestinvoker$getProtocol_b2af2a2de155d6f3564a200a8d3634cdf6f57aa2.invoke(Unknown Source) at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29) at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141) at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147) at io.quarkus.vertx.core.runtime.VertxCoreRecorder$15.runWith(VertxCoreRecorder.java:638) at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2675) at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2654) at org.jboss.threads.EnhancedQueueExecutor.runThreadBody(EnhancedQueueExecutor.java:1627) at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1594) at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11) at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:1583) Caused by: com.rabbitmq.client.ShutdownSignalException: clean connection shutdown; protocol method: #method<connection.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0) at com.rabbitmq.utility.ValueOrException.getValue(ValueOrException.java:66) at com.rabbitmq.utility.BlockingValueOrException.uninterruptibleGetValue(BlockingValueOrException.java:36) at com.rabbitmq.client.impl.AMQChannel$BlockingRpcContinuation.getReply(AMQChannel.java:552) at com.rabbitmq.client.impl.AMQChannel.privateRpc(AMQChannel.java:316) at com.rabbitmq.client.impl.AMQChannel.exnWrappingRpc(AMQChannel.java:152) ... 39 more

I already tried to increase the RabbitMQ heartbeat frequency in the RabbitMQ configuration (heartbeat = 5) but I still encounter the same problem.

Do you have any idea why this happens? By the way, wouldn't it be more practical to have an option to make this fail gracefully, that is, not return code 500 to the client application? (i.e. via an option set by an environment variable) I would appreciate any input on that.

Thank you!

Sincerely, Alexander Schreiber (schreiberstein)

schreiberstein avatar Jun 20 '25 13:06 schreiberstein

Greetings,

first of, thank you very much for the creation of this plugin and your continued efforts.

I am currently experiencing issues when the plugin is active, causing Keycloak to throw error 500 to user requests due to the plugin losing its connection to the upstream RabbitMQ server.

Setup:

  • Debian GNU/Linux Docker host (amd64)
  • Keycloak 26.2
  • RabbitMQ 4.1 (direct AMQP connection, no SSL)
  • Plugin version 0.9.1 (latest available binary)
  • Both containers run on the same host, in the same docker-compose stack, in the same network (= no networking issues, no firewall)

After a couple of requests, I receive the following stack traces in the Keycloack Docker log (the client application receives HTTP code 500).

Error: 2025-06-18 12:58:30,036 ERROR [org.keycloak.services.error.KeycloakErrorHandler] (executor-thread-301) Uncaught server error: java.io.IOException at com.rabbitmq.client.impl.AMQChannel.wrap(AMQChannel.java:140) at com.rabbitmq.client.impl.AMQChannel.wrap(AMQChannel.java:136) at com.rabbitmq.client.impl.AMQChannel.exnWrappingRpc(AMQChannel.java:158) at com.rabbitmq.client.impl.ChannelN.open(ChannelN.java:136) at com.rabbitmq.client.impl.ChannelManager.createChannel(ChannelManager.java:189) at com.rabbitmq.client.impl.AMQConnection.createChannel(AMQConnection.java:638) at com.rabbitmq.client.impl.recovery.AutorecoveringConnection.createChannel(AutorecoveringConnection.java:174) at com.vymalo.keycloak.webhook.AmqpWebhookHandler.initHandler(AmqpWebhookHandler.kt:139) at com.vymalo.keycloak.webhook.AbstractWebhookEventListenerFactory.ensureParametersInit(AbstractWebhookEventListenerFactory.kt:39) at com.vymalo.keycloak.webhook.AbstractWebhookEventListenerFactory.create(AbstractWebhookEventListenerFactory.kt:32) at com.vymalo.keycloak.webhook.AbstractWebhookEventListenerFactory.create(AbstractWebhookEventListenerFactory.kt:16) at org.keycloak.services.DefaultKeycloakSession.getOrCreateProvider(DefaultKeycloakSession.java:184) at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:195) at org.keycloak.models.KeycloakBeanProducer_ProducerMethod_getKeycloakSession_XoSEUTXOsE3bpqXlGMAykCiECUM_ClientProxy.getProvider(Unknown Source) at org.keycloak.events.EventBuilder.lambda$getEventListeners$1(EventBuilder.java:94) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179) at java.base/java.util.HashMap$ValueSpliterator.forEachRemaining(HashMap.java:1787) at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:575) at java.base/java.util.stream.AbstractPipeline.evaluateToArrayNode(AbstractPipeline.java:260) at java.base/java.util.stream.ReferencePipeline.toArray(ReferencePipeline.java:616) at java.base/java.util.stream.ReferencePipeline.toArray(ReferencePipeline.java:622) at java.base/java.util.stream.ReferencePipeline.toList(ReferencePipeline.java:627) at org.keycloak.events.EventBuilder.getEventListeners(EventBuilder.java:96) at org.keycloak.events.EventBuilder.<init>(EventBuilder.java:74) at org.keycloak.events.EventBuilder.<init>(EventBuilder.java:62) at org.keycloak.services.resources.RealmsResource.getProtocol(RealmsResource.java:117) at org.keycloak.services.resources.RealmsResource$quarkusrestinvoker$getProtocol_b2af2a2de155d6f3564a200a8d3634cdf6f57aa2.invoke(Unknown Source) at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29) at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141) at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147) at io.quarkus.vertx.core.runtime.VertxCoreRecorder$15.runWith(VertxCoreRecorder.java:638) at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2675) at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2654) at org.jboss.threads.EnhancedQueueExecutor.runThreadBody(EnhancedQueueExecutor.java:1627) at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1594) at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11) at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:1583) Caused by: com.rabbitmq.client.ShutdownSignalException: clean connection shutdown; protocol method: #method<connection.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0) at com.rabbitmq.utility.ValueOrException.getValue(ValueOrException.java:66) at com.rabbitmq.utility.BlockingValueOrException.uninterruptibleGetValue(BlockingValueOrException.java:36) at com.rabbitmq.client.impl.AMQChannel$BlockingRpcContinuation.getReply(AMQChannel.java:552) at com.rabbitmq.client.impl.AMQChannel.privateRpc(AMQChannel.java:316) at com.rabbitmq.client.impl.AMQChannel.exnWrappingRpc(AMQChannel.java:152) ... 39 more

I already tried to increase the RabbitMQ heartbeat frequency in the RabbitMQ configuration (heartbeat = 5) but I still encounter the same problem.

Do you have any idea why this happens? By the way, wouldn't it be more practical to have an option to make this fail gracefully, that is, not return code 500 to the client application? (i.e. via an option set by an environment variable) I would appreciate any input on that.

Thank you!

Sincerely, Alexander Schreiber (schreiberstein)

Hello @schreiberstein .

The log entry com.rabbitmq.client.ShutdownSignalException: clean connection shutdown; protocol method: #method<connection.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0) indicates a clean connection shutdown from RabbitMQ's perspective. The reply-code=200 Captured.my attention and I think it confirms that this closure was intentional and expected by the RabbitMQ server, not an abrupt or erroneous disconnection.

  • Enhance RabbitMQ Logging: Implement or augment existing RabbitMQ logging configurations to capture detailed information surrounding connection closures.
  • Investigate RabbitMQ Server Behavior: While the shutdown was clean, understanding why RabbitMQ initiated the closure is crucial.
  • Investigate Plugin-Side Behavior: Focus investigation on the plugin interacting with RabbitMQ. While Keycloak has been eliminated as a direct cause, the plugin's interaction with RabbitMQ, including its connection management and any programmed shutdown logic, should be thoroughly reviewed.

Motouom avatar Jun 20 '25 21:06 Motouom

Hello @schreiberstein! I'm glad the plugin is helpful for you! Can you provide a docker compose for better testing on our side?

stephane-segning avatar Jun 20 '25 23:06 stephane-segning

Hello @schreiberstein! I'm glad the plugin is helpful for you! Can you provide a docker compose for better testing on our side?

Hello @stephane-segning ! Thank you for your reply. There is nothing inherently special about my setup, but I was able to reproduce the error on this minimal setup attached to this comment.

keycloak-rabbitmq-01.tar.gz

Essentially, I just create the exchange in RabbitMQ, a dedicated user for keycloak, assign permissions for that user to access the exchange, and I can see that keycloak publishes these events alright. But it still loses connection.

I hope this is somehow helpful. Let me know if you need any more details.

schreiberstein avatar Jun 24 '25 07:06 schreiberstein

Hey @stephane-segning, were you able to take a look into this already? I do experience the same problem as @schreiberstein with my setup.

Also with just the bare minimum setup...

AndreV93 avatar Jul 04 '25 07:07 AndreV93

By the way, is this behavior expected? Seems like a new connection is created for each request? (See attached Screenshot)

Image

schreiberstein avatar Jul 04 '25 07:07 schreiberstein

Hello @schreiberstein @AndreV93, I could reproduce the error, thank you very much. I think I know where the issue is coming from. Lemme work on this

stephane-segning avatar Sep 05 '25 07:09 stephane-segning