[keycloak-user] OOM at startup with 1 million sessions
Nicolas Ocquidant
nocquidant at gmail.com
Tue Nov 20 05:04:09 EST 2018
Hi
My UC is to keep one year of sessions, this is what I have done to simulate
it:
1. I use JDBC to store 1 million of session objects, 2.8KB (in memory) each
2. I start one Infinispan node with passivation=false and shared=true, and
Xmx=8G
3. I start one Keycloak node configured with a remote-cache and Xmx=4G
Note that I use a remote-store in KC as it is the only way to set
passivation=false and shared=true (see
http://lists.jboss.org/pipermail/keycloak-user/2018-November/016180.html).
No problem in step 2, ISPN process is less than 300MB large in memory. But
after 3, ISPN process goes up to around 6GB.
See below for the traces, but basically I get OOM.
Using the debugger, I can see that getting the size of the cache is a
really slow operation, and bump memory to 3GB in ISPN process.
From
org.keycloak.models.sessions.infinispan.initializer.InfinispanCacheInitializer:
RemoteCacheSessionsLoader.computeLoaderContext(KeycloakSession session)
// ...
int sessionsTotal = remoteCache.size(); <--- HERE
//...
}
And then (OOM here):
InfinispanCacheInitializer.startLoadingImpl(InitializerState state,
SessionLoader.LoaderContext ctx) {
// ...
for (Future<WorkerResult> future : futures) {
// Called 4X (ie the number of segments), but 1st one does not
terminate: OOM
// ->
org.infinispan.distexec.DefaultExecutorService$LocalDistributedTaskPart
WorkerResult result = future.get(); <--- Very slow and bump mem to 8GB
// ...
}
So, with 1M of sessions in store, I cannot get KC/ISPN to start. And I am
far from my goal which is to keep one year of sessions (which has been
estimated to ~52M of sessions)...
Is it something I can't achieve with KC/ISPN?
Any help appreciated.
Thanks
nick
Note, versions I used are:
* ISPN 9.4.1 Wildfly
* KC 4.6.0 Wildfly
-- ISPN process
10:42:22,969 ERROR [stderr] (Periodic Recovery) Exception in thread
"Periodic Recovery" java.lang.OutOfMemoryError: Java heap space
10:42:22,977 ERROR [stderr] (Periodic Recovery) at
sun.text.resources.fr.FormatData_fr.getContents(FormatData_fr.java:86)
10:42:22,975 ERROR
[org.infinispan.persistence.jdbc.connectionfactory.ManagedConnectionFactory]
(pool-9-thread-1) ISPN008018: Sql failure retrieving connection from
datasource: java.sql.SQLException: javax.resource.ResourceException:
IJ000456: Unchecked throwable in ManagedConnection.getConnection()
cl=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener at 3e3890ff[state=NORMAL
managed
connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection at 3f033728
connection handles=0 lastReturned=1542706942971 lastValidated=1542706738387
lastCheckedOut=1542706916019 trackByTx=false
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool at 2772dcff
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool at 5e82b87d[pool=InfinispanDS]
xaResource=LocalXAResourceImpl at 308d2c98[connectionListener=3e3890ff
connectionManager=1691f7d6 warned=false currentXid=null
productName=PostgreSQL productVersion=10.5
jndiName=java:jboss/datasources/InfinispanDS] txSync=null]
at
org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:146)
at
org.jboss.as.connector.subsystems.datasources.WildFlyDataSource.getConnection(WildFlyDataSource.java:64)
at
org.infinispan.persistence.jdbc.connectionfactory.ManagedConnectionFactory.getConnection(ManagedConnectionFactory.java:83)
at
org.infinispan.persistence.jdbc.stringbased.JdbcStringBasedStore.purge(JdbcStringBasedStore.java:461)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.lambda$purgeExpired$6(PersistenceManagerImpl.java:459)
at java.util.ArrayList.forEach(ArrayList.java:1257)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.purgeExpired(PersistenceManagerImpl.java:462)
at
org.infinispan.expiration.impl.ClusterExpirationManager.processExpiration(ClusterExpirationManager.java:119)
at
org.infinispan.expiration.impl.ExpirationManagerImpl$ScheduledTask.run(ExpirationManagerImpl.java:245)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: javax.resource.ResourceException: IJ000456: Unchecked throwable
in ManagedConnection.getConnection()
cl=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener at 3e3890ff[state=NORMAL
managed
connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection at 3f033728
connection handles=0 lastReturned=1542706942971 lastValidated=1542706738387
lastCheckedOut=1542706916019 trackByTx=false
pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool at 2772dcff
mcp=SemaphoreConcurrentLinkedQueueManagedConnectionPool at 5e82b87d[pool=InfinispanDS]
xaResource=LocalXAResourceImpl at 308d2c98[connectionListener=3e3890ff
connectionManager=1691f7d6 warned=false currentXid=null
productName=PostgreSQL productVersion=10.5
jndiName=java:jboss/datasources/InfinispanDS] txSync=null]
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:811)
at
org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:138)
... 15 more
Caused by: java.lang.OutOfMemoryError: Java heap space
-- KC process
10:42:23,216 WARN [org.infinispan.client.hotrod.impl.protocol.Codec21]
(Thread-0) ISPN004005: Error received from the server:
java.lang.RuntimeException: java.sql.SQLException: Error
java.sql.SQLException: Error
java.lang.OutOfMemoryError: Java heap space
10:42:23,359 WARN
[org.keycloak.models.sessions.infinispan.remotestore.RemoteCacheSessionsLoader]
(pool-16-thread-4) Error loading sessions from remote cache 'sessions' for
segment '3':
org.infinispan.client.hotrod.exceptions.HotRodClientException:Request for
messageId=55 returned server error (status=0x85):
java.lang.RuntimeException: java.sql.SQLException: Error
java.sql.SQLException: Error
java.lang.OutOfMemoryError: Java heap space
at
org.infinispan.client.hotrod.impl.protocol.Codec20.checkForErrorsInResponseStatus(Codec20.java:333)
at
org.infinispan.client.hotrod.impl.protocol.Codec20.readHeader(Codec20.java:179)
at
org.infinispan.client.hotrod.impl.transport.netty.HeaderDecoder.decode(HeaderDecoder.java:138)
at
org.infinispan.client.hotrod.impl.transport.netty.HintedReplayingDecoder.callDecode(HintedReplayingDecoder.java:98)
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
at
io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
at
io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
at
io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)
at
io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
at
io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:647)
at
io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:582)
at
io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:499)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:461)
at
io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
More information about the keycloak-user
mailing list