High heap retention in stdout LoggingWriter's StringBuilder buffer

Solution Verified - Updated

Environment

  • JBoss Enterprise Application Platform (EAP)

Issue

  • We experienced an OutOfMemoryError that was generated from something writing messages through System.out:
Caused by: java.lang.OutOfMemoryError: Java heap space
	at java.util.Arrays.copyOf(Arrays.java:2894) [rt.jar:1.6.0_41]
	at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:117) [rt.jar:1.6.0_41]
	at java.lang.StringBuilder.append(StringBuilder.java:147) [rt.jar:1.6.0_41]
	at java.lang.StringBuilder.append(StringBuilder.java:188) [rt.jar:1.6.0_41]
	at org.jboss.logmanager.formatters.Formatters$JustifyingFormatStep.render(Formatters.java:250) [jboss-logmanager-1.5.8.Final-redhat-1.jar:1.5.8.Final-redhat-1]
	at org.jboss.logmanager.formatters.MultistepFormatter.format(MultistepFormatter.java:83) [jboss-logmanager-1.5.8.Final-redhat-1.jar:1.5.8.Final-redhat-1]
	at org.jboss.logmanager.ExtFormatter.format(ExtFormatter.java:32) [jboss-logmanager-1.5.8.Final-redhat-1.jar:1.5.8.Final-redhat-1]
	at org.jboss.logmanager.handlers.WriterHandler.doPublish(WriterHandler.java:46) [jboss-logmanager-1.5.8.Final-redhat-1.jar:1.5.8.Final-redhat-1]
	at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:76) [jboss-logmanager-1.5.8.Final-redhat-1.jar:1.5.8.Final-redhat-1]
	at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:302) [jboss-logmanager-1.5.8.Final-redhat-1.jar:1.5.8.Final-redhat-1]
	at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:310) [jboss-logmanager-1.5.8.Final-redhat-1.jar:1.5.8.Final-redhat-1]
	at org.jboss.logmanager.Logger.logRaw(Logger.java:719) [jboss-logmanager-1.5.8.Final-redhat-1.jar:1.5.8.Final-redhat-1]
	at org.jboss.logmanager.Logger.log(Logger.java:504) [jboss-logmanager-1.5.8.Final-redhat-1.jar:1.5.8.Final-redhat-1]
	at org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71)
	at org.jboss.stdio.WriterOutputStream.finish(WriterOutputStream.java:143)
	at org.jboss.stdio.WriterOutputStream.write(WriterOutputStream.java:112)
	at java.io.PrintStream.write(PrintStream.java:447) [rt.jar:1.6.0_41]
	at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:220) [rt.jar:1.6.0_41]
	at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:290) [rt.jar:1.6.0_41]
	at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:103) [rt.jar:1.6.0_41]
	at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185) [rt.jar:1.6.0_41]
	at java.io.PrintStream.write(PrintStream.java:494) [rt.jar:1.6.0_41]
	at java.io.PrintStream.print(PrintStream.java:636) [rt.jar:1.6.0_41]
	at java.io.PrintStream.println(PrintStream.java:773) [rt.jar:1.6.0_41]
	at org.jboss.stdio.StdioContext$DelegatingPrintStream.println(StdioContext.java:474)
  • The heap dump from the OutOfMemoryError showed that there were very large StringBuilders containing repeating messages. That StringBuilder was the stdout org.jboss.stdio.LoggingWriter's buffer.

Resolution

  • Avoid the use of System.out.print. Use System.out.println instead or a proper Logger.
  • Disable stdout logging to avoid logging of and heap retention of such messages in the buffer, for example in your logging subsystem:
      <logger category="stdout">
          <level name="OFF"/>
      </logger>

Root Cause

  • High amounts of successive strings without a '\n' are written to System.out.print.
  • The LoggerWriter will buffer until a '\n' is seen at which point it will flush the buffer to a logger. That would mean any messages written with System.out.print that don't have a '\n' in the string would buffer until the first'\n' is finally found.
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.