OutOfMemoryError on native heap when upgrading from java 6 to java 7

Question

We recently upgraded our large webapp (running on jboss 5) from java 6 to java 7.

Within hours, we saw an OutOfMemory error, and it looks like it's the native heap which ran out.

We are running 32 bit JVM so are limited to 4GB, and the JVM was allocated 2GB.

Under java 6 the whole process occupied about 2.3GB, but with java 7 this is greatly increased, and we hit the 4GB limit without a full GC being triggered because the Java heap was still not full.

The stack trace showed that the XML unmarshalling code is creating new SAXParserFactory on each request, and the Inflater class for unzipping the jar file stores loads of data in the native heap (~200,000 Inflater instances). This strikes me as fairly inefficient - both the new SAXParserFactory and the multiple Inflaters. Maybe this is a red herring, but I don't have the java 6 version of this to compare behaviours.

By running the gc manually every few hours, the application ticks happily along for days without any problems. But that's not a solution.

The question is why has the memory allocation increased by a whopping 1.5GB, and how do I stop that happening?

I would expect a newer java version be more efficient, faster and so on. But instead we have what looks like a memory leak in the JVM.

Anyway the stack trace is as follows:

# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 512128 bytes for Chunk::new
# An error report file with more information is saved as:
# /opt/SP/apps/er_core/current/hs_err_pid25455.log
00:49:30,072 ERROR [[DecouplingProcessServlet]] Servlet.service() for servlet DecouplingProcessServlet threw exception
java.lang.OutOfMemoryError
    at java.util.zip.Inflater.init(Native Method)
    at java.util.zip.Inflater.<init>(Inflater.java:101)
    at java.util.zip.ZipFile.getInflater(ZipFile.java:450)
    at java.util.zip.ZipFile.getInputStream(ZipFile.java:369)
    at org.jboss.virtual.plugins.context.zip.ZipFileWrapper.openStream(ZipFileWrapper.java:214)
    at org.jboss.virtual.plugins.context.zip.ZipEntryContext.openStream(ZipEntryContext.java:1066)
    at org.jboss.virtual.plugins.context.zip.ZipEntryHandler.openStream(ZipEntryHandler.java:153)
    at org.jboss.virtual.VirtualFile.openStream(VirtualFile.java:230)
    at org.jboss.virtual.plugins.vfs.VirtualFileURLConnection.getInputStream(VirtualFileURLConnection.java:93)
    at java.net.URLClassLoader.getResourceAsStream(URLClassLoader.java:233)
    at javax.xml.parsers.SecuritySupport$4.run(SecuritySupport.java:94)
    at java.security.AccessController.doPrivileged(Native Method)
    at javax.xml.parsers.SecuritySupport.getResourceAsStream(SecuritySupport.java:87)
    at javax.xml.parsers.FactoryFinder.findJarServiceProvider(FactoryFinder.java:283)
    at javax.xml.parsers.FactoryFinder.find(FactoryFinder.java:255)
    at javax.xml.parsers.SAXParserFactory.newInstance(SAXParserFactory.java:126)
    at javax.xml.bind.helpers.AbstractUnmarshallerImpl.getXMLReader(AbstractUnmarshallerImpl.java:100)
    at javax.xml.bind.helpers.AbstractUnmarshallerImpl.unmarshal(AbstractUnmarshallerImpl.java:157)
    at javax.xml.bind.helpers.AbstractUnmarshallerImpl.unmarshal(AbstractUnmarshallerImpl.java:204)
    at com.mycompany.global.er.decoupling.util.xml.JAXBHelper.bind(JAXBHelper.java:88)
    at com.mycompany.global.er.decoupling.util.xml.JAXBHelper.bind(JAXBHelper.java:56)
    at com.mycompany.global.er.decoupling.DecouplingProcessServlet.doPost(DecouplingProcessServlet.java:163)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:190)
    at org.apache.catalina.valves.RequestFilterValve.process(RequestFilterValve.java:269)
    at org.apache.catalina.valves.RemoteAddrValve.invoke(RemoteAddrValve.java:81)
    at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:92)
    at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
    at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at pk.vodafone.valves.PKAccessLogValve.invoke(PKAccessLogValve.java:547)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:829)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:598)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
    at java.lang.Thread.run(Thread.java:724)
00:49:30,117 ERROR [CoyoteAdapter] An exception or error occurred in the container during the request processing
java.lang.NoClassDefFoundError: javax/servlet/ServletRequestAttributeEvent
    at org.apache.catalina.connector.Request.setAttribute(Request.java:1452)
    at org.apache.catalina.core.StandardWrapperValve.exception(StandardWrapperValve.java:523)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:280)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:190)
    at org.apache.catalina.valves.RequestFilterValve.process(RequestFilterValve.java:269)
    at org.apache.catalina.valves.RemoteAddrValve.invoke(RemoteAddrValve.java:81)
    at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:92)
    at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
    at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at pk.vodafone.valves.PKAccessLogValve.invoke(PKAccessLogValve.java:547)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:829)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:598)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
    at java.lang.Thread.run(Thread.java:724)
Caused by: java.lang.ClassNotFoundException: Unexpected error during load of: javax.servlet.ServletRequestAttributeEvent, msg=null
    at org.jboss.classloader.spi.base.ClassLoaderManager.process(ClassLoaderManager.java:173)
    at org.jboss.classloader.spi.base.BaseClassLoaderDomain.loadClass(BaseClassLoaderDomain.java:259)
    at org.jboss.classloader.spi.base.BaseClassLoaderDomain.loadClass(BaseClassLoaderDomain.java:1102)
    at org.jboss.classloader.spi.base.BaseClassLoader.loadClassFromDomain(BaseClassLoader.java:772)
    at org.jboss.classloader.spi.base.BaseClassLoader.loadClass(BaseClassLoader.java:415)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
    ... 19 more
Caused by: java.lang.OutOfMemoryError
    at java.util.zip.Inflater.init(Native Method)
    at java.util.zip.Inflater.<init>(Inflater.java:101)
    at java.util.zip.ZipFile.getInflater(ZipFile.java:450)
    at java.util.zip.ZipFile.getInputStream(ZipFile.java:369)
    at org.jboss.virtual.plugins.context.zip.ZipFileWrapper.openStream(ZipFileWrapper.java:214)
    at org.jboss.virtual.plugins.context.zip.ZipEntryContext.openStream(ZipEntryContext.java:1066)
    at org.jboss.virtual.plugins.context.zip.ZipEntryHandler.openStream(ZipEntryHandler.java:153)
    at org.jboss.virtual.VirtualFile.openStream(VirtualFile.java:230)
    at org.jboss.classloading.spi.vfs.policy.VFSClassLoaderPolicy.getResourceAsStream(VFSClassLoaderPolicy.java:483)
    at org.jboss.classloader.spi.base.BaseClassLoader$2.run(BaseClassLoader.java:508)
    at org.jboss.classloader.spi.base.BaseClassLoader$2.run(BaseClassLoader.java:506)
    at java.security.AccessController.doPrivileged(Native Method)
    at org.jboss.classloader.spi.base.BaseClassLoader.loadClassLocally(BaseClassLoader.java:504)
    at org.jboss.classloader.spi.base.BaseClassLoader.loadClassLocally(BaseClassLoader.java:481)
    at org.jboss.classloader.spi.base.BaseDelegateLoader.loadClass(BaseDelegateLoader.java:134)
    at org.jboss.classloader.spi.filter.FilteredDelegateLoader.loadClass(FilteredDelegateLoader.java:131)
    at org.jboss.classloader.spi.base.ClassLoadingTask$ThreadTask.run(ClassLoadingTask.java:452)
    at org.jboss.classloader.spi.base.ClassLoaderManager.nextTask(ClassLoaderManager.java:258)
    at org.jboss.classloader.spi.base.ClassLoaderManager.process(ClassLoaderManager.java:152)
    ... 24 more
[thread 123611 also had an error]

A couple of useful links I found on this topic:

http://practicalcloudcomputing.com/post/444939181/outofmemoryjnigzip

http://www.javacodegeeks.com/2013/01/java-heap-space-native-heap-and-memory-problems.html

JVM options are as follows:

-server -Xms2048m -Xmx2048m -XX:NewSize=384m 
-XX:MaxNewSize=384m 
-XX:SurvivorRatio=4 
-XX:MinHeapFreeRatio=11 
-XX:PermSize=80m 
-verbose:gc 
-XX:+PrintGCDateStamps 
-XX:+PrintGCDetails 
-XX:+DisableExplicitGC 
-Djava.awt.headless=TRUE -DUseSunHttpHandler=TRUE -Dsun.net.client.defaultConnectTimeout=25000 
-Dsun.net.client.defaultReadTimeout=50000 
-Dfile.encoding=UTF-8 
-Xloggc:gc.log 
Dcom.sun.management.jmxremote.port=9003 
-Dcom.sun.management.jmxremote.authenticate=FALSE 
-Dcom.sun.management.jmxremote.ssl=FALSE 
-Duser.language=de 
-Duser.region=DE 
-Duser.country=DE 
-Djboss.vfs.cache.TimedPolicyCaching.lifetime=1440000 
-DVFjavaWL=er.core.de

Update

A bit more analysis. Here's my naive interpretation of what's happening with the xml parsing:

1. We have a singleton JAXBHelper class, with an instance-level JAXBContext (this is a threadsafe object).
2. Every time a request comes in, we attempt to bind the incoming xml string to a Java object (generated previously by JAXB from the xsd).
3. The bind method creates an instance-level unmarshaller (these are not threadsafe, but cheap to create).
4. The bind method then calls the unmarshaller's unmarshal(InputStream) method.
5. Now the javax.xml.bind.helpers.AbstractUnmarshallerImpl then calls SAXParserFactory.newInstance, which in turn calls a classloader, which in turn requires an Inflater.

Surely the implementation (we're using jaxb-ri 2.2.7) should keep the SAXParserFactory or the SAXParser and re-use them? I note that neither are threadsafe, so it could be done with a ThreadLocal. Or could the Inflater instances be re-used?

Does that fact that these are not being re-used mean that I'm not dereferencing my objects? The UnMarshaller doesn't seem to have any kind of close method.

Answer 1

The memory leak is caused by Inflaters that are not closed.
It looks like these Inflaters fall down to Old Generation and their finalizers are not called as long as Full GC is not triggered.

In order to prevent JRE from scanning through all JAR files looking for SAXParserFactory, you may create $JAVA_HOME/jre/lib/jaxp.properties file containing the following line:

javax.xml.parsers.SAXParserFactory=com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl

It might be also useful to remove -XX:+DisableExplicitGC option since JVM runtime depends on System.gc call when it detects a shortage of native memory.