[
https://issues.apache.org/jira/browse/LOG4J2-880?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14183871#comment-14183871
]
Laurent Cohen commented on LOG4J2-880:
--------------------------------------
I was able able to reproduce the same problem in similar circumstances - and
registered this [JPPF bug|http://www.jppf.org/tracker/tbg/jppf/issues/JPPF-343]
with full details.
My analysis of the problem:
* the log4j2 console appender, upon creation, will point to the stream defined
for the child process' standard output, which is a pipe between the process and
its parent process
* the child process is configured to redirect the standard output to a file
"system_out.log". This happens after the console appender's initialization.
* The problem is that, unless configured otherwise, the console appender will
continue to write to the same stream, from which the parent process is not
reading. Thus the stream buffer will fill quickly, until the appender blocks
because there's is no space left in the buffer
* a workaround consists in setting the follow="true" attribute in the appender
configuration (it is "false" by default)
Thus, I believe that the behavior of the console appender is in fact to be
expected. You can reproduce the same hanging behavior without Log4j2, using
System.out.println() statements in the child process: if the parent process is
not reading from the stream on the other side of the pipe, the child process
will also block on a System.out.println() at some point in time.
Furthermore, as far as I know the Java I/O stream APIs do not provide any way
to determine the state of a buffered stream, in particular you can't know how
much space is available in the buffer, so it's very difficult if not impossible
to determine whether the next write() operation will block or not.
To conclude, my take on this is that it may not be a Log4j2 bug and the only
thing, if any, that should be changed, is the default value for the "follow"
attribute.
> ConsoleAppender hangs when writing to System.out in a spawned JVM
> -----------------------------------------------------------------
>
> Key: LOG4J2-880
> URL: https://issues.apache.org/jira/browse/LOG4J2-880
> Project: Log4j 2
> Issue Type: Bug
> Affects Versions: 2.0.2
> Reporter: Daniel Widdis
>
> I am using Log4J2 in an application using Java Parallel Processing Framework
> (www.jppf.org). One of the features of JPPF is node provisioning, in which a
> node process can spawn additional JVMs. However, since the spawned JVMs do
> not have a "console" the only way to access System.out is by redirecting it
> to a file, which is done automatically.
> By default, the ConsoleAppender sets {{follow="false"}}. However, rather
> than exiting gracefully doing nothing, it locks an OutputStreamManger and
> never releases it. This causes the application to hang.
> The problem is easily worked around by setting {{follow="true"}} on the
> appender. However, I propose that the default behavior for {{follow="false"}}
> when System.out is unavailable (as in a spawned JVM) should simply return
> without doing anything, rather than locking resources.
> Relevant stack trace of the thread holding the lock is shown below. The
> {{writeBytes()}} method never returned. Other threads attempted to write but
> were blocked because of this lock.
> "pool-5-thread-6" prio=6 tid=0x000000000c0c2000 nid=0x2ce4 runnable
> [0x000000000d9ae000]
> java.lang.Thread.State: RUNNABLE
> at java.io.FileOutputStream.writeBytes(Native Method)
> at java.io.FileOutputStream.write(Unknown Source)
> at java.io.BufferedOutputStream.write(Unknown Source)
> - locked <0x00000000d0063960> (a java.io.BufferedOutputStream)
> at java.io.PrintStream.write(Unknown Source)
> - locked <0x00000000d0063940> (a java.io.PrintStream)
> at
> org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:122)
> - locked <0x00000000d00638e0> (a
> org.apache.logging.log4j.core.appender.OutputStreamManager)
> at
> org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:136)
> at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:106)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:97)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:428)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:407)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:410)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:365)
> at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:112)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:1336)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1325)
> at
> org.apache.logging.log4j.spi.AbstractLogger.warn(AbstractLogger.java:1738)
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org
