[ 
https://issues.apache.org/jira/browse/LOG4J2-880?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14186914#comment-14186914
 ] 

Daniel Widdis commented on LOG4J2-880:
--------------------------------------

Yes, Log4j 2.1 behaves the same way because the underlying Appender code is the 
same:
* {{follow}} defaults to "false" in ConsoleAppender.java:89
* In ConsoleAppender.java:179, the Appender's OutputStream is initialized.  
When {{follow}} is false, it points to the existing (at initialization) 
System.out PrintStream, maintaining that reference even if later calls to 
System.setOut() change it.  When {{follow}} is true, it points to a new wrapper 
object that will write to the current value of System.out when called later.  
This is exactly as is documented.  (The documentation does not indicate what 
the default is.)

As Laurent mentioned, it's not really a Log4j bug. But the choice of the 
default does have some impact:

If default is false:
- Probably slightly faster calls directly to the (old) System.out PrintStream
- Requires developers who use System.setOut() to still take action to read the 
old PrintStream to avoid blocking, (or use redirect methods before creating the 
spawned process to begin with) or make it clear to users that they need to 
configure Log4j to follow the redirect
- Risks applications blocking on writes to the log, a non-obvious bug without 
getting a thread dump

If default is true:
- Incompatible with some setups (Windows/JANSI) which will require false
- Requires slightly more overhead with a wrapper object
- More robust to developer choices of methods for System.out redirection



> 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: Wish
>    Affects Versions: 2.0.2
>            Reporter: Daniel Widdis
>            Priority: Minor
>
> 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

Reply via email to