High CPU and heap usage in JBoss Session Replication with HashMaps stored as session attributes

Solution Verified - Updated

Environment

  • JBoss Enterprise Application Platform (EAP)
  • JBoss Enterprise Portal Platform (EPP)

Issue

  • High CPU is seen in a thread currently processing session replication:
"http-0.0.0.0-8080-1" daemon prio=10 tid=0x00002aaacdec2800 nid=0x1d1a runnable [0x00002aaad631f000]
   java.lang.Thread.State: RUNNABLE
	at java.util.Arrays.copyOf(Arrays.java:2786)
	at java.io.ByteArrayOutputStream.write(ByteArrayOutputStream.java:94)
	- locked <0x00000006a9b01800> (a java.io.ByteArrayOutputStream)
	at java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1847)
	at java.io.ObjectOutputStream$BlockDataOutputStream.setBlockDataMode(ObjectOutputStream.java:1756)
	at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1169)
	at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:330)
	at java.util.HashMap.writeObject(HashMap.java:1001)
	at sun.reflect.GeneratedMethodAccessor396.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:945)
	at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1469)
	at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1400)
	at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1158)
	at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1518)
	at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1483)
	at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1400)
	at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1158)
	at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:330)
	at java.util.HashMap.writeObject(HashMap.java:1001)
	at sun.reflect.GeneratedMethodAccessor396.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:945)
	at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1469)
	at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1400)
	at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1158)
	at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:330)
	at org.jboss.ha.framework.server.SimpleCachableMarshalledValue.serialize(SimpleCachableMarshalledValue.java:352)
	at org.jboss.ha.framework.server.SimpleCachableMarshalledValue.writeExternal(SimpleCachableMarshalledValue.java:333)
	- locked <0x00000006a948c978> (a org.jboss.ha.framework.server.SimpleCachableMarshalledValue)
	at java.io.ObjectOutputStream.writeExternalData(ObjectOutputStream.java:1429)
	at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1398)
	at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1158)
	at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:330)
	at org.jboss.cache.marshall.CacheMarshaller200.marshallObject(CacheMarshaller200.java:460)
	at org.jboss.cache.marshall.CommandAwareRpcDispatcher$ReplicationTask.call(CommandAwareRpcDispatcher.java:355)
	at org.jboss.cache.util.concurrent.WithinThreadExecutor.submit(WithinThreadExecutor.java:82)
	at org.jboss.cache.marshall.CommandAwareRpcDispatcher.invokeRemoteCommands(CommandAwareRpcDispatcher.java:210)
	at org.jboss.cache.RPCManagerImpl.callRemoteMethods(RPCManagerImpl.java:744)
	at org.jboss.cache.RPCManagerImpl.callRemoteMethods(RPCManagerImpl.java:712)
	at org.jboss.cache.RPCManagerImpl.callRemoteMethods(RPCManagerImpl.java:717)
	at org.jboss.cache.interceptors.BaseRpcInterceptor.replicateCall(BaseRpcInterceptor.java:161)
	at org.jboss.cache.interceptors.BaseRpcInterceptor.replicateCall(BaseRpcInterceptor.java:135)
	at org.jboss.cache.interceptors.BaseRpcInterceptor.replicateCall(BaseRpcInterceptor.java:107)
	at org.jboss.cache.interceptors.ReplicationInterceptor.handleCrudMethod(ReplicationInterceptor.java:160)
	at org.jboss.cache.interceptors.ReplicationInterceptor.visitPutDataMapCommand(ReplicationInterceptor.java:113)
	at org.jboss.cache.commands.write.PutDataMapCommand.acceptVisitor(PutDataMapCommand.java:104)
	at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
	at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
	at org.jboss.cache.commands.AbstractVisitor.visitPutDataMapCommand(AbstractVisitor.java:60)
	at org.jboss.cache.commands.write.PutDataMapCommand.acceptVisitor(PutDataMapCommand.java:104)
	at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
	at org.jboss.cache.interceptors.TxInterceptor.attachGtxAndPassUpChain(TxInterceptor.java:301)
	at org.jboss.cache.interceptors.TxInterceptor.handleDefault(TxInterceptor.java:283)
	at org.jboss.cache.commands.AbstractVisitor.visitPutDataMapCommand(AbstractVisitor.java:60)
	at org.jboss.cache.commands.write.PutDataMapCommand.acceptVisitor(PutDataMapCommand.java:104)
	at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
	at org.jboss.cache.interceptors.CacheMgmtInterceptor.visitPutDataMapCommand(CacheMgmtInterceptor.java:97)
	at org.jboss.cache.commands.write.PutDataMapCommand.acceptVisitor(PutDataMapCommand.java:104)
	at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
	at org.jboss.cache.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:178)
	at org.jboss.cache.interceptors.InvocationContextInterceptor.visitPutDataMapCommand(InvocationContextInterceptor.java:64)
	at org.jboss.cache.commands.write.PutDataMapCommand.acceptVisitor(PutDataMapCommand.java:104)
	at org.jboss.cache.interceptors.InterceptorChain.invoke(InterceptorChain.java:287)
	at org.jboss.cache.invocation.CacheInvocationDelegate.invokePut(CacheInvocationDelegate.java:705)
	at org.jboss.cache.invocation.CacheInvocationDelegate.put(CacheInvocationDelegate.java:519)
	at org.jboss.ha.cachemanager.CacheManagerManagedCache.put(CacheManagerManagedCache.java:283)
	at org.jboss.web.tomcat.service.session.distributedcache.impl.jbc.JBossCacheWrapper.put(JBossCacheWrapper.java:162)
	at org.jboss.web.tomcat.service.session.distributedcache.impl.jbc.AbstractJBossCacheService.storeSessionData(AbstractJBossCacheService.java:404)
	at org.jboss.web.tomcat.service.session.ClusteredSession.processSessionReplication(ClusteredSession.java:1192)
	- locked <0x00000006a6f62b20> (a org.jboss.web.tomcat.service.session.SessionBasedClusteredSession)
	at org.jboss.web.tomcat.service.session.JBossCacheManager.processSessionRepl(JBossCacheManager.java:2221)
	at org.jboss.web.tomcat.service.session.JBossCacheManager.storeSession(JBossCacheManager.java:321)
	- locked <0x00000006a6f62b20> (a org.jboss.web.tomcat.service.session.SessionBasedClusteredSession)
	at org.jboss.web.tomcat.service.session.InstantSnapshotManager.snapshot(InstantSnapshotManager.java:51)
  • This same thread is also leaking memory in a local byte[] until an OOME

Resolution

Root Cause

  • A HashMap was placed in a session attribute and accessed concurrently while it was being written out for session replication. HashMaps are not thread-safe and are known to cause high CPU loops if accessed concurrently. Using them in session attributes like this with concurrent requests to that session can result in loops in HashMap.writeObject calls, causing it to fill the heap with repetitive data during those loops.
  • Content from issues.jboss.org is not included.PBR-408: EPP can cause such an issue by using a HashMap for the org.jboss.portletbridge.RequestScopeManager in session attributes.

Diagnostic Steps

  • Troubleshoot with heap dumps, thread dumps, CPU data and other diagnostic steps as described in Java application "java.lang.OutOfMemoryError: Java heap space" and Java application high CPU
  • Check in the heap dump if the HashMap being written out is tied to org.jboss.portletbridge.RequestScopeManager
  • Check in the thread dumps if other threads can be seen blocked on the same org.jboss.web.tomcat.service.session.SessionBasedClusteredSession used by the high CPU/heap thread. This would indicate concurrent access to the session and potentially to its attributes and any HashMaps held here.
Components
Category

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.