Receiving 'OutOfMemory: Java heap space' due to JBoss Serialization attempting to allocate a huge StringBuffer

Solution Verified - Updated

Environment

  • Red Hat JBoss Enterprise Application Platform (EAP) 5.1.0 or earlier
  • 1.6 JDK+

Issue

  • Receiving 'OutOfMemory: Java heap space' due to JBoss Serialization attempting to allocate a huge StringBuffer. Sample stack trace:
2013-07-12 17:01:23,898 DEBUG [org.jboss.serial.util.StringUtil] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) Reading string with utfSize=90363601776499 isLong=true
2013-07-12 17:01:23,898 DEBUG [org.jboss.serial.util.StringUtil] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) readString::pulling data to Buffer at pos 0 size= 0
2013-07-12 17:01:23,898 DEBUG [org.jboss.serial.util.StringUtil] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) readString::pulling data to Buffer at pos 1024 size= 1024
2013-07-12 08:33:44,718 WARN  [org.jboss.seam.Component] (ajp-127.0.0.1-8009-73) Exception calling component @Destroy method: org.example.DefaultClass
javax.ejb.EJBException: java.lang.RuntimeException: java.io.IOException
	at org.jboss.ejb3.tx.Ejb3TxPolicy.handleExceptionInOurTx(Ejb3TxPolicy.java:77)
	at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:83)
	at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:190)
	at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
	at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76)
	at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
        [...]
Caused by: java.lang.OutOfMemoryError: Java heap space
	at java.lang.AbstractStringBuilder.<init>(AbstractStringBuilder.java:45)
	at java.lang.StringBuffer.<init>(StringBuffer.java:91)
	at org.jboss.serial.util.StringUtil.readString(StringUtil.java:295)
	at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readUTF(DataContainer.java:757)
	at org.jboss.serial.persister.ObjectInputStreamProxy.readUTF(ObjectInputStreamProxy.java:196)
	at org.jboss.serial.objectmetamodel.FieldsContainer.readField(FieldsContainer.java:147)
	at org.jboss.serial.objectmetamodel.FieldsContainer.readMyself(FieldsContainer.java:218)
	at org.jboss.serial.persister.ObjectInputStreamProxy.readFields(ObjectInputStreamProxy.java:224)
	at java.io.File.readObject(File.java:1937)
	at sun.reflect.GeneratedMethodAccessor3089.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        [...]

Resolution

  • Upgrade to EAP 5.1.1 or later, as it includes a newer version of JBoss Serialization which prevents this issue. You need to run with -Dorg.jboss.serial.SYNC_SERIALIZATION_BINARY_FORMATS=true to enable the fix.

Root Cause

  • After investigation the implementation of File changed between java 5 & 6. The new implementation use ObjectInputStream.readFields() instead of ObjectInputStream.defaultReadObject(); this results in deserialization attempts to allocate a large StringBuffer (too large to ever fit in the heap) as the utfSize is incorrectly read.

Diagnostic Steps

  • Obtained a heap dump from the event, and analyzing this we were unable to view any large objects that resulted in the OutOfMemory error being thrown.
  • Enabled and examined garbage collection logs, noticed multiple full GCs reclaiming much of the heap, but still the error was thrown with ~2 GB available in the OldGen:
2013-07-12T16:54:40.962-0700: 5119.862: [GC 5119.862: [ParNew: 1208141K->35990K(1887488K), 0.0858430 secs]5119.948: [CMS: 1229169K->1246159K(3145728K), 4.7694230 secs] 2436050K->1246159K(5033216K), [CMS Perm : 234792K->234740K(524288K)], 4.8557070 secs] [Times: user=4.77 sys=0.00, real=4.85 secs]
2013-07-12T16:54:45.818-0700: 5124.718: [Full GC 5124.718: [CMS: 1246159K->1244194K(3145728K), 3.9327150 secs] 1246159K->1244194K(5033216K), [CMS Perm : 234740K->233562K(524288K)], 3.9331120 secs] [Times: user=3.81 sys=0.00, real=3.94 secs]
2013-07-12T16:54:52.789-0700: 5131.689: [GC 5131.689: [ParNew: 268676K->28329K(1887488K), 0.0691470 secs]5131.759: [CMS: 1244194K->1236753K(3145728K), 4.7881800 secs] 1512871K->1236753K(5033216K), [CMS Perm : 236257K->234333K(524288K)], 4.8577640 secs] [Times: user=4.75 sys=0.00, real=4.86 secs]
2013-07-12T16:54:57.647-0700: 5136.547: [Full GC 5136.547: [CMS: 1236753K->1234854K(3145728K), 3.7663280 secs] 1236753K->1234854K(5033216K), [CMS Perm : 234333K->233567K(524288K)], 3.7667090 secs] [Times: user=3.66 sys=0.00, real=3.77 secs]
2013-07-12T16:55:01.911-0700: 5140.811: [GC 5140.811: [ParNew: 164506K->17985K(1887488K), 0.0340150 secs]5140.845: [CMS: 1234854K->1222870K(3145728K), 3.9924020 secs] 1399360K->1222870K(5033216K), [CMS Perm : 233838K->231950K(524288K)], 4.0269170 secs] [Times: user=3.93 sys=0.00, real=4.03 secs]
2013-07-12T16:55:05.938-0700: 5144.838: [Full GC 5144.838: [CMS: 1222870K->1221869K(3145728K), 3.7152860 secs] 1222870K->1221869K(5033216K), [CMS Perm : 231950K->231685K(524288K)], 3.7156550 secs] [Times: user=3.61 sys=0.00, real=3.72 secs]
  • Enabled debugging on the following paths:
org.jboss.serial.persister.RegularObjectPersister
org.jboss.serial.util.StringUtil
org.jboss.serial.objectmetamodel.ObjectDescriptorFactory

The above debugging statements showed the utfSize in the server logs, along with the class that was attempting to be deserialized.

SBR
Product(s)
Components
Category
Tags

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.