Keycloak stopped for an unknown reason

[Arnault]

Hello,

I have deployed keycloak quarkus in a kubernetes cluster and, when our test suite is runed against keycloak, I can see that keycloak exits, and I'm not sure but it could be because the DefaultCacheManager exits.

Does anyone have a clue about why keycloak can be exiting ?

Below is the relevant trace after buming the log level to DEBUG:

2022-05-30 08:55:52,531 DEBUG [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-0) Executed scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$994/0x0000000100b24c4
2022-05-30 08:55:53,328 DEBUG [org.infinispan.manager.DefaultCacheManager] (Thread-10) Stopping cache manager -77d6778765-rxtg6-24355
2022-05-30 08:55:53,333 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache realms on keycloak
2022-05-30 08:55:53,350 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache authenticationSessions on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,351 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache authenticationSessions
2022-05-30 08:55:53,354 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache authenticationSessions left
2022-05-30 08:55:53,356 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache sessions on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,356 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache sessions
2022-05-30 08:55:53,356 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache sessions left
2022-05-30 08:55:53,358 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache authorizationRevisions on keycloak
2022-05-30 08:55:53,361 DEBUG [org.infinispan.transaction.impl.TransactionTable] (Thread-10) Wait for on-going transactions to finish for 30 seconds.
2022-05-30 08:55:53,361 DEBUG [org.infinispan.transaction.impl.TransactionTable] (Thread-10) All transactions terminated
2022-05-30 08:55:53,361 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Brute Force Protector) new JtaTransactionWrapper
222-05-30 08:55:53,361 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Brute Force Protector) was existing? false
2022-05-30 08:55:53,362 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache clientSessions on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,362 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache clientSessions
2022-05-30 08:55:53,362 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Brute Force Protector) JtaTransactionWrapper  commit
2022-05-30 08:55:53,362 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache clientSessions left
2022-05-30 08:55:53,362 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Brute Force Protector) JtaTransactionWrapper end
2022-05-30 08:55:53,363 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache work on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,363 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache work
2022-05-30 08:55:53,363 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache work left
2022-05-30 08:55:53,362 DEBUG [org.hibernate.internal.SessionFactoryImpl] (Shutdown thread) HHH000031: Closing
2022-05-30 08:55:53,364 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache keys on keycloak
2022-05-30 08:55:53,365 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache org.infinispan.CLIENT_SERVER_TX_TABLE on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,365 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache org.infinispan.CLIENT_SERVER_TX_TABLE
2022-05-30 08:55:53,365 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache org.infinispan.CLIENT_SERVER_TX_TABLE left
2022-05-30 08:55:53,366 DEBUG [org.hibernate.type.spi.TypeConfiguration$Scope] (Shutdown thread) Un-scoping TypeConfiguration [org.hibernate.type.spi.TypeConfiguration$Scope@6e37ed97] fr
2022-05-30 08:55:53,366 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache loginFailures on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,367 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache loginFailures
2022-05-30 08:55:53,367 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache loginFailures left
2022-05-30 08:55:53,367 DEBUG [org.hibernate.service.internal.AbstractServiceRegistryImpl] (Shutdown thread) Implicitly destroying ServiceRegistry on de-registration of all child Service
2022-05-30 08:55:53,367 DEBUG [org.infinispan.quarkus.hibernate.cache.QuarkusInfinispanRegionFactory] (Shutdown thread) Stop region factory
2022-05-30 08:55:53,367 DEBUG [org.infinispan.quarkus.hibernate.cache.QuarkusInfinispanRegionFactory] (Shutdown thread) Clear region references
2022-05-30 08:55:53,367 DEBUG [org.hibernate.boot.registry.internal.BootstrapServiceRegistryImpl] (Shutdown thread) Implicitly destroying Boot-strap registry on de-registration of all ch
2022-05-30 08:55:53,367 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache users on keycloak
2022-05-30 08:55:53,368 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache offlineClientSessions on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,368 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache offlineClientSessions
222-05-30 08:55:53,368 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache offlineClientSessions left
222-05-30 08:55:53,369 DEBUG [org.keycloak.executors.DefaultExecutorsProviderFactory] (Shutdown thread) Shutting down executor for task 'storage-provider-threads'
2022-05-30 08:55:53,369 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache authorization on keycloak
222-05-30 08:55:53,370 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache realmRevisions on keycloak
2022-05-30 08:55:53,371 DEBUG [org.infinispan.transaction.impl.TransactionTable] (Thread-10) Wait for on-going transactions to finish for 30 seconds.
2022-05-30 08:55:53,371 DEBUG [org.infinispan.transaction.impl.TransactionTable] (Thread-10) All transactions terminated
2022-05-30 08:55:53,371 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache org.infinispan.CONFIG on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,372 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache org.infinispan.CONFIG
2022-05-30 08:55:53,372 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache org.infinispan.CONFIG left
2022-05-30 08:55:53,373 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache org.infinispan.COUNTER on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,373 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache org.infinispan.COUNTER
2022-05-30 08:55:53,373 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache org.infinispan.COUNTER left
2022-05-30 08:55:53,374 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache offlineSessions on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,374 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache offlineSessions
2022-05-30 08:55:53,374 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache offlineSessions left
2022-05-30 08:55:53,375 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache actionTokens on -77d6778765-rxtg6-24355
2022-05-30 08:55:53,375 DEBUG [org.infinispan.topology.LocalTopologyManagerImpl] (Thread-10) Node -77d6778765-rxtg6-24355 leaving cache actionTokens
2022-05-30 08:55:53,375 DEBUG [org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy] (Thread-10) The last node of cache actionTokens left
2022-05-30 08:55:53,376 DEBUG [org.infinispan.cache.impl.CacheImpl] (Thread-10) Stopping cache userRevisions on keycloak
2022-05-30 08:55:53,377 DEBUG [org.infinispan.transaction.impl.TransactionTable] (Thread-10) Wait for on-going transactions to finish for 30 seconds.
2022-05-30 08:55:53,377 DEBUG [org.infinispan.transaction.impl.TransactionTable] (Thread-10) All transactions terminated
2022-05-30 08:55:53,378 INFO  [org.infinispan.CLUSTER] (Thread-10) ISPN000080: Disconnecting JGroups channel `ISPN`
2022-05-30 08:55:53,383 DEBUG [org.jgroups.protocols.UDP] (Thread-10) -77d6778765-rxtg6-24355: closing sockets and stopping threads
2022-05-30 08:55:53,384 DEBUG [org.jgroups.protocols.UDP] (Thread-10) -77d6778765-rxtg6-24355: multicast socket closed
2022-05-30 08:55:53,384 DEBUG [org.jgroups.protocols.UDP] (ucast-receiver-5,-77d6778765-rxtg6-24355) -77d6778765-rxtg6-24355: receiver socket is closed, exception
2022-05-30 08:55:53,384 DEBUG [org.jgroups.protocols.UDP] (mcast-receiver-6,-77d6778765-rxtg6-24355) -77d6778765-rxtg6-24355: receiver socket is closed, exception
2022-05-30 08:55:53,385 DEBUG [org.jgroups.protocols.UDP] (mcast-receiver-6,-77d6778765-rxtg6-24355) mcast-receiver thread terminated
2022-05-30 08:55:53,385 DEBUG [org.jgroups.protocols.UDP] (ucast-receiver-5,-77d6778765-rxtg6-24355) ucast-receiver thread terminated
2022-05-30 08:55:53,394 DEBUG [org.infinispan.manager.DefaultCacheManager] (Thread-10) Stopped cache manager -77d6778765-rxtg6-24355
2022-05-30 08:55:53,395 DEBUG [org.keycloak.connections.infinispan.RemoteCacheProvider] (Shutdown thread) Shutdown 0 registered secured remoteCache managers
2022-05-30 08:55:53,410 DEBUG [org.hibernate.orm.beans] (Shutdown thread) HHH10005004: Stopping BeanContainer : io.quarkus.hibernate.orm.runtime.cdi.QuarkusArcBeanContainer@47e84b6d
2022-05-30 08:55:53,417 DEBUG [io.quarkus.arc.impl] (Shutdown thread) ArC DI container shut down
2022-05-30 08:55:53,425 DEBUG [io.netty.buffer.PoolThreadCache] (executor-thread-5) Freed 1 thread-local buffer(s) from thread: executor-thread-5
2022-05-30 08:55:53,429 DEBUG [io.netty.buffer.PoolThreadCache] (vert.x-eventloop-thread-3) Freed 12 thread-local buffer(s) from thread: vert.x-eventloop-thread-3
2022-05-30 08:55:53,429 DEBUG [io.netty.buffer.PoolThreadCache] (vert.x-eventloop-thread-1) Freed 13 thread-local buffer(s) from thread: vert.x-eventloop-thread-1
2022-05-30 08:55:53,429 DEBUG [io.netty.buffer.PoolThreadCache] (vert.x-eventloop-thread-0) Freed 14 thread-local buffer(s) from thread: vert.x-eventloop-thread-0
2022-05-30 08:55:53,431 DEBUG [io.netty.buffer.PoolThreadCache] (vert.x-eventloop-thread-2) Freed 12 thread-local buffer(s) from thread: vert.x-eventloop-thread-2
2022-05-30 08:55:53,434 DEBUG [io.quarkus.thread-pool] (Shutdown thread) loop: 1, remaining: 60000000000, intervalRemaining: 5000000000, interruptRemaining: 10000000000
2022-05-30 08:55:53,435 INFO  [io.quarkus] (Shutdown thread) Keycloak stopped in 0.106s

Regards,

Aranult

[Arnault]

To answer myself quarkus is handling SIGTERM signal to stop the quarkus application, and kubernetes sends such SIGNAL when it wants to restart pods.