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.

Faddist

So, you found a solution (running gc). What is the question, then? – Mlle

Running gc manually every 4 hours is not a solution, it's a workaround. – Faddist

But still, you don't have a question there. You are just describing a state of affairs. Assuming we can't change Java 7's native code, what do you expect as an answer? – Mlle

@Mlle you fit your name :p The fact of the matter is that someone in the vast SO crowd may have encountered, and cured, this problem... Anyway, is there a way to use another XML parser implementation? – Orlosky

I have added a question. Ideally an answer would explain why this memory leak is happening and give me a way to fix it – Faddist

Show us your list of JVM options and hs_err.log if possible. – Polyester

OK. I think the first link you added explains why this is happening: memory is released in finalize(), finalize() is not called until major gc. Now that you have a more efficient JVM, it does not overrun the java heap, therefore does not call gc, which the less efficient Java 6 probably did. Can't offer a non-workaround solution, though. – Mlle

Let's try a different angle, though: why is it unzipping so much? Can you elaborate on what exactly is being unzipped and why? Perhaps you can use whatever it is without compression. – Mlle

@Mlle I have added some analysis. And yes I had reached a similar conclusion - that it could be a symptom of the new JVM being more efficient. But why are these Inflater objects being created in such large numbers, and not re-used or dereferenced? – Faddist

Why don't you parse the XML yourself prior to giving it to JAXB? You could then manage XML Parsers (StAX/SAX/DOM) as you see fit. This does not answer the OOME question but will probably give you a reliable solution. – Nebraska

@Nebraska I'm not sure I understand your idea - can you elaborate? – Faddist

@Faddist You unmarshall an input stream now. So JAXB under the hood creates a parser and parses the XML and the processes the output (via SAX). Why don't you create a SAX or StAX or whatever parser factory, parse the XML and feed the result to JAXB for unmarshalling? Take an StAX parser and feed the XMLWhateverReader (don't remember how it's called) to JAXB. You won't be loading the SAXParserFactory on each request then, right? So you'll workaround the problem. Anyway my point is that if you overtake the parser management from JAXB you may be able to control it better / more efficiently. – Nebraska

How about pooling the marshallers/unmarshallers as described in this article? This will limit the number of new ones you are creating, and, supposedly, the number of their calls to their class loaders. – Mlle

@Mlle I have never seen guarantees that marshallers/unmarshallers are reusable. So it's tecnically not safe to pool them. – Nebraska

Well, it says here that pooling them is allowed. They are not thread-safe, but they are reentrant. – Mlle

@Nebraska thanks for the clarification. I think I have already done this, but it's not enabled in prod. The code can optionally create a XMLStreamReader (from an XMLInputFactory) for the input string, then pass it to the unmarshal method. Now I need to persuade the Ops team to switch it on... – Faddist

@Mlle That guide is unofficial and quite old, not written/supported by the current JAXB dev team AFAIK... – Nebraska

@Nebraska Here is the documentation for ri 2.2.7, which says, and I quote: Different threads may reuse one Unmarshaller instance, as long as you don't use one instance from two threads at the same time. – Mlle

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.

Polyester

Thanks, I will ask the Ops guys to try this out, and let you know if it works. – Faddist

Do you have some documentation / link to back up your statement "JVM runtime depends on System.gc call when it detects a shortage of native memory." ? I can show this to the ops guys (who want to keep the DisableExplicitGC flag) – Faddist

@Faddist E.g. Bits.reserveMemory and FileChannelImpl.map call System.gc to force object finalization if native mmap or malloc fail. – Polyester