[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF subversion and git services (JIRA)]

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

ASF subversion and git services commented on LOG4J2-1748:
-

Commit 571fb8df680b0db94ad1b6afed478e915b3411a3 in logging-log4j2's branch 
refs/heads/master from [~mikaelstaldal]
[ https://git-wip-us.apache.org/repos/asf?p=logging-log4j2.git;h=571fb8d ]

LOG4J2-1748 and LOG4J2-1780 Restore interrupted flag on thread


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF subversion and git services (JIRA)]

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

ASF subversion and git services commented on LOG4J2-1748:
-

Commit d5071900b0c72fccd8bf7e2ccee3a8164d4fdb25 in logging-log4j2's branch 
refs/heads/master from [~mikaelstaldal]
[ https://git-wip-us.apache.org/repos/asf?p=logging-log4j2.git;h=d507190 ]

Merge remote-tracking branch 
'origin/LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext' into 
LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF subversion and git services (JIRA)]

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

ASF subversion and git services commented on LOG4J2-1748:
-

Commit d5071900b0c72fccd8bf7e2ccee3a8164d4fdb25 in logging-log4j2's branch 
refs/heads/master from [~mikaelstaldal]
[ https://git-wip-us.apache.org/repos/asf?p=logging-log4j2.git;h=d507190 ]

Merge remote-tracking branch 
'origin/LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext' into 
LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


Github user asfgit closed the pull request at:

https://github.com/apache/logging-log4j2/pull/55


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> XmlConfiguration[location=C:\Users\danidemi\workspace\bug-log4j2-hanging-up-before-shutdown\target\classes\log4j2.xml]...
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


Github user rgoers commented on the issue:

https://github.com/apache/logging-log4j2/pull/55
  
I manually approved it.


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


Github user jvz commented on the issue:

https://github.com/apache/logging-log4j2/pull/55
  
Did GitHub parse your comment or did you manually approve the PR?


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF subversion and git services (JIRA)]

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

ASF subversion and git services commented on LOG4J2-1748:
-

Commit d5071900b0c72fccd8bf7e2ccee3a8164d4fdb25 in logging-log4j2's branch 
refs/heads/LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext from 
[~mikaelstaldal]
[ https://git-wip-us.apache.org/repos/asf?p=logging-log4j2.git;h=d507190 ]

Merge remote-tracking branch 
'origin/LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext' into 
LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF subversion and git services (JIRA)]

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

ASF subversion and git services commented on LOG4J2-1748:
-

Commit 571fb8df680b0db94ad1b6afed478e915b3411a3 in logging-log4j2's branch 
refs/heads/LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext from 
[~mikaelstaldal]
[ https://git-wip-us.apache.org/repos/asf?p=logging-log4j2.git;h=571fb8d ]

LOG4J2-1748 and LOG4J2-1780 Restore interrupted flag on thread


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF subversion and git services (JIRA)]

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

ASF subversion and git services commented on LOG4J2-1748:
-

Commit d5071900b0c72fccd8bf7e2ccee3a8164d4fdb25 in logging-log4j2's branch 
refs/heads/LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext from 
[~mikaelstaldal]
[ https://git-wip-us.apache.org/repos/asf?p=logging-log4j2.git;h=d507190 ]

Merge remote-tracking branch 
'origin/LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext' into 
LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


Github user mikaelstaldal commented on a diff in the pull request:

https://github.com/apache/logging-log4j2/pull/55#discussion_r96677972
  
--- Diff: 
log4j-core/src/main/java/org/apache/logging/log4j/core/appender/mom/kafka/KafkaManager.java
 ---
@@ -73,17 +74,19 @@ public boolean releaseSub(final long timeout, final 
TimeUnit timeUnit) {
 private void closeProducer(final long timeout, final TimeUnit 
timeUnit) {
 if (producer != null) {
 // This thread is a workaround for this Kafka issue: 
https://issues.apache.org/jira/browse/KAFKA-1660
-final Runnable task = new Runnable() {
+   final Thread closeThread = new Log4jThread(new Runnable() {
 @Override
 public void run() {
 if (producer != null) {
 producer.close();
 }
 }
-};
+}, "KafkaManager-CloseThread");
+closeThread.setDaemon(true); // avoid blocking JVM shutdown
+closeThread.start();
 try {
-getLoggerContext().submitDaemon(task).get(timeout, 
timeUnit);
-} catch (InterruptedException | ExecutionException | 
TimeoutException e) {
+closeThread.join(timeUnit.toMillis(timeout));
+} catch (final InterruptedException ignore) {
--- End diff --

OK.


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


Github user jvz commented on a diff in the pull request:

https://github.com/apache/logging-log4j2/pull/55#discussion_r96668615
  
--- Diff: 
log4j-core/src/main/java/org/apache/logging/log4j/core/appender/mom/kafka/KafkaManager.java
 ---
@@ -73,17 +74,19 @@ public boolean releaseSub(final long timeout, final 
TimeUnit timeUnit) {
 private void closeProducer(final long timeout, final TimeUnit 
timeUnit) {
 if (producer != null) {
 // This thread is a workaround for this Kafka issue: 
https://issues.apache.org/jira/browse/KAFKA-1660
-final Runnable task = new Runnable() {
+   final Thread closeThread = new Log4jThread(new Runnable() {
 @Override
 public void run() {
 if (producer != null) {
 producer.close();
 }
 }
-};
+}, "KafkaManager-CloseThread");
+closeThread.setDaemon(true); // avoid blocking JVM shutdown
+closeThread.start();
 try {
-getLoggerContext().submitDaemon(task).get(timeout, 
timeUnit);
-} catch (InterruptedException | ExecutionException | 
TimeoutException e) {
+closeThread.join(timeUnit.toMillis(timeout));
+} catch (final InterruptedException ignore) {
--- End diff --

The thread would have been interrupted for a reason, so it's generally good 
to handle the exception and reset the interrupt flag (it doesn't necessarily 
cause an exception to be thrown; code has to manually check a thread's 
interrupt status according to the javadocs).


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


Github user mikaelstaldal commented on a diff in the pull request:

https://github.com/apache/logging-log4j2/pull/55#discussion_r96594353
  
--- Diff: 
log4j-core/src/main/java/org/apache/logging/log4j/core/appender/mom/kafka/KafkaManager.java
 ---
@@ -73,17 +74,19 @@ public boolean releaseSub(final long timeout, final 
TimeUnit timeUnit) {
 private void closeProducer(final long timeout, final TimeUnit 
timeUnit) {
 if (producer != null) {
 // This thread is a workaround for this Kafka issue: 
https://issues.apache.org/jira/browse/KAFKA-1660
-final Runnable task = new Runnable() {
+   final Thread closeThread = new Log4jThread(new Runnable() {
 @Override
 public void run() {
 if (producer != null) {
 producer.close();
 }
 }
-};
+}, "KafkaManager-CloseThread");
+closeThread.setDaemon(true); // avoid blocking JVM shutdown
+closeThread.start();
 try {
-getLoggerContext().submitDaemon(task).get(timeout, 
timeUnit);
-} catch (InterruptedException | ExecutionException | 
TimeoutException e) {
+closeThread.join(timeUnit.toMillis(timeout));
+} catch (final InterruptedException ignore) {
--- End diff --

Should I? Why?


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


Github user mikaelstaldal commented on the issue:

https://github.com/apache/logging-log4j2/pull/55
  
I like my code :-)

(testing reviewing)


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


Github user jvz commented on a diff in the pull request:

https://github.com/apache/logging-log4j2/pull/55#discussion_r96528818
  
--- Diff: 
log4j-core/src/main/java/org/apache/logging/log4j/core/appender/mom/kafka/KafkaManager.java
 ---
@@ -73,17 +74,19 @@ public boolean releaseSub(final long timeout, final 
TimeUnit timeUnit) {
 private void closeProducer(final long timeout, final TimeUnit 
timeUnit) {
 if (producer != null) {
 // This thread is a workaround for this Kafka issue: 
https://issues.apache.org/jira/browse/KAFKA-1660
-final Runnable task = new Runnable() {
+   final Thread closeThread = new Log4jThread(new Runnable() {
 @Override
 public void run() {
 if (producer != null) {
 producer.close();
 }
 }
-};
+}, "KafkaManager-CloseThread");
+closeThread.setDaemon(true); // avoid blocking JVM shutdown
+closeThread.start();
 try {
-getLoggerContext().submitDaemon(task).get(timeout, 
timeUnit);
-} catch (InterruptedException | ExecutionException | 
TimeoutException e) {
+closeThread.join(timeUnit.toMillis(timeout));
+} catch (final InterruptedException ignore) {
--- End diff --

Shouldn't you reset the interrupt flag after catching this?


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


GitHub user mikaelstaldal opened a pull request:

https://github.com/apache/logging-log4j2/pull/55

LOG4J2-1748 and LOG4J2-1780

Remove executor service from LoggerContext.

You can merge this pull request into a Git repository by running:

$ git pull https://github.com/apache/logging-log4j2 
LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext

Alternatively you can review and apply these changes as the patch at:

https://github.com/apache/logging-log4j2/pull/55.patch

To close this pull request, make a commit to your master/trunk branch
with (at least) the following in the commit message:

This closes #55


commit 162a5e33ace3f1b4adf0726502083d0efb1e799a
Author: Mikael Ståldal 
Date:   2017-01-12T11:14:18Z

LOG4J2-1748 and LOG4J2-1780 Remove ExecutorServices from LoggerContext

commit 9f2b0984682f708adb0359646127043b4f1561ae
Author: Mikael Ståldal 
Date:   2017-01-12T21:36:25Z

LOG4J2-1748 and LOG4J2-1780 Remove non-relevant documentation

commit d3e04250d2e314aa33a51247698b3ed46503afd5
Author: Mikael Ståldal 
Date:   2017-01-12T21:36:58Z

LOG4J2-1748 and LOG4J2-1780 Fix changelog

commit bd649ed99069add1a2b46b9e8e1079803d9507ad
Author: Mikael Ståldal 
Date:   2017-01-15T14:51:17Z

Merge branch 'master' into 
LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext

# Conflicts:
#   
log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationScheduler.java
#   src/changes/changes.xml

commit 80879c7dd6c76700a575c4dfe4e42bfde205faef
Author: Mikael Ståldal 
Date:   2017-01-15T14:56:42Z

LOG4J2-1748 fix changelog

commit e21a07e353a748e3a7dbefce20bf414aa425e1c7
Author: Mikael Ståldal 
Date:   2017-01-15T15:13:41Z

LOG4J2-1748 revert some changes

commit e390ad368f5549c2415856d9176a0cf32c2ced40
Author: Mikael Ståldal 
Date:   2017-01-15T15:29:31Z

LOG4J2-1748 revert some changes

commit 4fb38c620aaf62b37642387237da2a06c58b4d8c
Author: Mikael Ståldal 
Date:   2017-01-15T15:32:50Z

LOG4J2-1748 fix

commit f6341ad505c298fcf66c9b3183873cc5f6c4e844
Author: Mikael Ståldal 
Date:   2017-01-15T16:14:12Z

LOG4J2-1748 fix

commit 527b125c31e3ce654657bf7df5a9b2fc27d8ffd4
Author: Mikael Ståldal 
Date:   2017-01-15T16:18:39Z

LOG4J2-1748 revert some changes

commit 1974c8202eed10d0c971f493ca2c09a05bfc6cbb
Author: Mikael Ståldal 
Date:   2017-01-17T20:53:39Z

Merge branch 'master' into 
LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext

# Conflicts:
#   
log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingFileManager.java
#   src/changes/changes.xml

commit 3917b66ec79cc8fe103a6eb49badf934d6e64182
Author: Mikael Ståldal 
Date:   2017-01-17T20:57:26Z

LOG4J2-1748 fix merge issue




> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


Github user mikaelstaldal closed the pull request at:

https://github.com/apache/logging-log4j2/pull/54


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> XmlConfiguration[location=C:\Users\danidemi\workspace\bug-log4j2-hanging-up-before-shutdown\target\classes\log4j2.xml]...
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[ASF GitHub Bot (JIRA)]

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

ASF GitHub Bot commented on LOG4J2-1748:


GitHub user mikaelstaldal opened a pull request:

https://github.com/apache/logging-log4j2/pull/54

LOG4J2-1748 and LOG4J2-1780

Remove executor services from LoggerContext

You can merge this pull request into a Git repository by running:

$ git pull https://github.com/apache/logging-log4j2 
LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext

Alternatively you can review and apply these changes as the patch at:

https://github.com/apache/logging-log4j2/pull/54.patch

To close this pull request, make a commit to your master/trunk branch
with (at least) the following in the commit message:

This closes #54


commit 162a5e33ace3f1b4adf0726502083d0efb1e799a
Author: Mikael Ståldal 
Date:   2017-01-12T11:14:18Z

LOG4J2-1748 and LOG4J2-1780 Remove ExecutorServices from LoggerContext

commit 9f2b0984682f708adb0359646127043b4f1561ae
Author: Mikael Ståldal 
Date:   2017-01-12T21:36:25Z

LOG4J2-1748 and LOG4J2-1780 Remove non-relevant documentation

commit d3e04250d2e314aa33a51247698b3ed46503afd5
Author: Mikael Ståldal 
Date:   2017-01-12T21:36:58Z

LOG4J2-1748 and LOG4J2-1780 Fix changelog

commit bd649ed99069add1a2b46b9e8e1079803d9507ad
Author: Mikael Ståldal 
Date:   2017-01-15T14:51:17Z

Merge branch 'master' into 
LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext

# Conflicts:
#   
log4j-core/src/main/java/org/apache/logging/log4j/core/config/ConfigurationScheduler.java
#   src/changes/changes.xml

commit 80879c7dd6c76700a575c4dfe4e42bfde205faef
Author: Mikael Ståldal 
Date:   2017-01-15T14:56:42Z

LOG4J2-1748 fix changelog

commit e21a07e353a748e3a7dbefce20bf414aa425e1c7
Author: Mikael Ståldal 
Date:   2017-01-15T15:13:41Z

LOG4J2-1748 revert some changes

commit e390ad368f5549c2415856d9176a0cf32c2ced40
Author: Mikael Ståldal 
Date:   2017-01-15T15:29:31Z

LOG4J2-1748 revert some changes

commit 4fb38c620aaf62b37642387237da2a06c58b4d8c
Author: Mikael Ståldal 
Date:   2017-01-15T15:32:50Z

LOG4J2-1748 fix

commit f6341ad505c298fcf66c9b3183873cc5f6c4e844
Author: Mikael Ståldal 
Date:   2017-01-15T16:14:12Z

LOG4J2-1748 fix

commit 527b125c31e3ce654657bf7df5a9b2fc27d8ffd4
Author: Mikael Ståldal 
Date:   2017-01-15T16:18:39Z

LOG4J2-1748 revert some changes




> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Mikael Ståldal
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


I have a solution for this and LOG4J-1780, please review branch 
LOG4J2-1748and1780-remove-ExecutorService-from-LoggerContext

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


I don't think it is that complicated to keep track of tasks in flight, just use 
{{ExecutorService.awaitTermination(timeout, timeUnit)}}, as already done in 
{{ExecutorServices.shutdown(timeout, timeUnit)}}. The only missing part is to 
apply some default timeout (such as one second) when the {{timeout}} parameter 
is zero (which it will be unless explicitly set by user).

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

I disagree. We've seen problems in the past when the Async rollover actions 
(the compression) was done in a daemon thread. A normal (unforced) shutdown 
could result in corrupted compressed log files. 

We either have a separate non-daemon ExecutorService, or spawn ad hoc 
non-daemon threads, or we do something complicated where the Shutdown hook 
tracks all Async tasks that are in flight. 
Spawning ad hoc non-daemon threads for the async rollover tasks  is probably 
simplest. 

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


The root cause of the problem is using non-daemon threads. If we stop doing 
that, this problem will go away. ConfigurationScheduler uses daemon threads, 
which is good.

Those executor services added to LoggerContext have caused two issues already, 
this one and LOG4J2-1780 (a potential resource leak).

If we remove them and use ConfigurationScheduler, as Ralph suggests, those two 
issues will go away and we will not have to fix them separately.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


Yes, I agree.

But while waiting for us to fix it, it can be useful to have a workaround. And 
it is a simpler workaround than {{Configurator.shutdown()}} as previously 
suggested.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Ralph Goers (JIRA)]

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

Ralph Goers commented on LOG4J2-1748:
-

I have no problem using the ThreadFactory to create the thread. 

As I pointed out in LOG4J2-1780, the reason for the name is that the 
ConfigurationScheduler is "owned" by the Configuration, so the name makes that 
relationship clear. It's purpose was to handle scheduling for anything 
associated with a configuration (which is almost everything). The only thing it 
really shouldn't handle is reconfiguration.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

It would be nice if the shutdown hook would be able to print a message like 
"Log4j2 shutdown hook is waiting for compress action  to complete ".

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

Probably best to have only one ExecutorService. 
Naming-wise, ConfigurationScheduler suggests a narrow scope. We should consider 
renaming it if the role of this service is to be extended for general purpose 
async work. 

I don't object to creating ad hoc Threads, but agree with Gary that we want to 
name Log4j threads uniformly so we want to go through our ThreadFactory and 
create Log4jThreads. 

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Ralph Goers (JIRA)]

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

Ralph Goers commented on LOG4J2-1748:
-

We have an ExecutorService. It is called ConfigurationScheduler. 
RollingFileManager and KafkaManager should be using that.

It is OK to create a Thread where it makes more sense than having a service.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Ralph Goers (JIRA)]

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

Ralph Goers commented on LOG4J2-1748:
-

Again, lets just get rid of these ExecutorService instances.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> XmlConfiguration[location=C:\Users\danidemi\workspace\bug-log4j2-hanging-up-before-shutdown\target\classes\log4j2.xml]...
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Ralph Goers (JIRA)]

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

Ralph Goers commented on LOG4J2-1748:
-

I don't think that is a great recommendation.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> XmlConfiguration[location=C:\Users\danidemi\workspace\bug-log4j2-hanging-up-before-shutdown\target\classes\log4j2.xml]...
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE XmlConfiguration notified 3 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Ralph Goers (JIRA)]

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

Ralph Goers commented on LOG4J2-1748:
-

I don't know why those two ThreadPoolExecutors were added.  The 
ConfigurationScheduler was added to be the single place that Log4j schedules 
work to be executed. I plan on modifying the RollingFileManager to use the 
ConfigurationScheduler to perform the rollover.  The only other thing using 
those ExecutorServices is the configuration file Watcher. What is interesting 
is that the WatchManager uses the ConfigurationScheduler to periodically check 
for events - so naturally the check happens on a Thread owned by the 
ConfigurationScheduler. When a file modification is found 
ConfigurationFileWatcher schedules another Thread to run to perform the 
reconfiguration. This used to be done by creating a Thread and running it. I 
guess Gary decided it was better to have an ExecutorService for this. 
Personally, I think this is wrong.  The reconfiguration shouldn't happen in a 
Thread owned by the ConfigurationScheduler because that will be stopped and 
restarted during reconfiguration. But I see no point in creating an 
ExecutorService to perform just this one task as it is overkill. 

I don't think this problem would exist if these ExecutorServices weren't 
present.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


But I think the proper way to handle this is to have our shutdown hook wait for 
the task to finish (with a timeout), as we currently do. Then we can safely do 
it with a daemon thread.

A library like Log4j should not start non-daemon threads since that will 
disrupt shutdown of the application, as shown by this bug. Remko's solution is 
just a work-around for a more fundamental underlying problem.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Gary Gregory (JIRA)]

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

Gary Gregory commented on LOG4J2-1748:
--

Yep, IIRC, that is why I did it that way.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> XmlConfiguration[location=C:\Users\danidemi\workspace\bug-log4j2-hanging-up-before-shutdown\target\classes\log4j2.xml]...
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE XmlConfiguration notified 3 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

I believe (I could be wrong) that the non-daemon thread was introduced to 
prevent the compress action from being interrupted if the application ended 
immediately after a rollover. 

True, if forcefully killed this may still happen, but it makes sense to do 
compression in a non-daemon thread. 

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


Created a bug for the failure to shut down old ExecutorServices: 
https://issues.apache.org/jira/browse/LOG4J2-1780

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> XmlConfiguration[location=C:\Users\danidemi\workspace\bug-log4j2-hanging-up-before-shutdown\target\classes\log4j2.xml]...
>

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


I am not sure that it will be dangerous to use a daemon thread since we have a 
shutdown hook. According to 
http://docs.oracle.com/javase/8/docs/api/java/lang/Runtime.html#addShutdownHook-java.lang.Thread-
 :

{code}
Note that daemon threads will continue to run during the shutdown sequence, as 
will non-daemon threads if shutdown was initiated by invoking the exit method. 
{code}

If there is a risk for partial rollover with daemon threads, that risk exist 
for non-daemon threads as well if the application exits with 
{{System.exit(int)}} (which is a quite common thing to do I guess).

I suggest that we remove the non-daemon executor pool and only have a daemon 
one. Then Remko's fix can be reverted.


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


After looking more closely at this, I think it actually make sense to have this 
separate. It is actually idle thread timeout, not shutdown timeout. It just 
happen to delay shutdown in some cases (when the app doesn't to 
{{System.exit(int)}}).

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


A simple workaround is to add System.exit(0) at the end of the main method.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> XmlConfiguration[location=C:\Users\danidemi\workspace\bug-log4j2-hanging-up-before-shutdown\target\classes\log4j2.xml]...
> 2016-12-22 22:13:36,382 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

I think it's a good idea to use the {{config.getShutdownTimeoutMillis}} for the 
ExecutorService also. As long as we use minimum 1 sec, that should be okay. I 
am just swamped with work and don't have time to make these changes.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

... and another good catch! Two actually.

LoggerContext.setConfiguration: I was looking at the code on my phone during 
the commute and I missed that. Yes, Executors are initialized during 
setConfiguration so they should be able to use 
{{config.getShutdownTimeoutMillis}}. By the way, looks like that value is zero 
if users don't specify anything. Zero is not a good threadpool timeout value 
(it is reasonable to let Threads live for at least 1 sec in the hope it can be 
reused for another task).

Also, it looks like the old ExecutorServices are not shut down when a 
reconfiguration happens.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


Anyway, we could change "shutdownTimeout" to a system property since it is new 
after the 2.7 release.

I put it as a configuration attribute since it is related to "shutdownHook" 
which is already there.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


I don't really understand why we can't use a configuration attribute for this 
since you have a configuration available when reading the system property 
(LoggerContext.setConfiguration). And it seems like the ExecutorService is 
created (and thus the system property read) each time a reconfiguration happens?

BTW, shouldn't the old one be shut down?

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

You wouldn't notice because I fixed it on Dec 27th by shortening the default 
keep-alive time for non-daemon threads from 60 seconds to 1 second. Before that 
you would only notice if the application shuts down immediately after 
triggering a rollover.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Ralph Goers (JIRA)]

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

Ralph Goers commented on LOG4J2-1748:
-

Has this been tested with the latest code in master?  I have been testing the 
rolling file appender all weekend and I am not noticing this.  I suspect this 
was fixed as part of LOG4J2-1653.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

Thank you for updating the JIRA. 
The fact that this is a Configuration attribute makes things difficult since 
the ExecutorServices live in the LoggerContext. The LoggerContext is created 
only once while the Configuration may be created many times (reconfiguration). 

So it may not be easy to combine the two. 


> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


I have added it to the JIRA now.

Here is goes also:

This is a new top-level attribute in the configuration: "shutdownTimeout". (Not 
a system property.)

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

Good point. Unfortunately, that JIRA doesn't document the name of the system 
property that was introduced. I would have to go and look at the code to see 
what that property is called in order to judge whether it makes sense for both 
use cases. Not sure when I'll have time for that. 

Conversations like this would go faster if we document more detail on our 
changes in JIRA. That would also be useful for users. 

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[JIRA]

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

Mikael Ståldal commented on LOG4J2-1748:


Wait, now when we have https://issues.apache.org/jira/browse/LOG4J2-1623, do we 
really need to add a new system property for this?

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>Assignee: Remko Popma
>  Labels: RollingFile, bug
> Fix For: 2.8
>
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Gary Gregory (JIRA)]

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

Gary Gregory commented on LOG4J2-1748:
--

I do not think we should change the thread pool type to daemon, that would be 
too dangerous. How about making the KAT configurable with possibly a short 
default KAT?

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>  Labels: RollingFile, bug
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> XmlConfiguration[location=C:\Users\danidemi\workspace\bug-log4j2-hanging-up-before-shutdown\target\classes\log4j2.xml]...
> 2016-12-22 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

I've tracked down the cause: Log4j creates two ThreadPoolExecutors, one daemon 
and one non-daemon. These executors are created with the default settings, 
which sets the thread keepAliveTime to one minute.

In the example, the application shuts down immediately after triggering a 
rollover. The rollover compresses the old file in a background thread in the 
non-daemon executor. Because the executor keeps this thread alive for one 
minute, and this is a non-daemon thread, the application as a whole is kept 
alive for one minute.

We could do the rollover in a daemon thread, but this may result in partial 
rollovers if the application exits before the rollover is complete. An 
alternative is to make the keepAliveTime for the non-daemon executor pool 
shorter (like 500 millis or one second or so).

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>  Labels: RollingFile, bug
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Remko Popma (JIRA)]

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

Remko Popma commented on LOG4J2-1748:
-

If Log4j delays shutdown by one minute that's not good...

Given that this only happens when a rollover actually happened, I suspect it 
has to do with the thread that executed the rollover action, or the threadpool 
holding that thread. 

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>  Labels: RollingFile, bug
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Daniele Demichelis (JIRA)]

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

Daniele Demichelis commented on LOG4J2-1748:


Hi [~garydgregory],
Configurator.shutdown(...) solved the problem, thx.

In the other hand, I was wondering... I come from years of using log4j 1.x and 
slf4j/logback where an explicit shutdown has never been needed. Can this 
behaviour of log4j2 be so counterintuitive that it is actually a bug ? I'm just 
exposing my thoughs. What do you think ?

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>  Labels: RollingFile, bug
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Gary Gregory (JIRA)]

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

Gary Gregory commented on LOG4J2-1748:
--

You could also try to add a call to Configurator.shutdown(...) at the end of 
your main. I did not realize that your example started Log4j implicitly but did 
not shutdown anything explicitly.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>  Labels: RollingFile, bug
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
> 

[jira] [Commented] (LOG4J2-1748) RollingFile appender prevents a stand alone application to terminate for as long as 60 sec

[Gary Gregory (JIRA)]

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

Gary Gregory commented on LOG4J2-1748:
--

I think the rollover happens on a separate thread. When log4j shutdown, it 
cleans up after itself and waits for threads to finish and files to be closed. 
You might be seeing a delay because of this.

> RollingFile appender prevents a stand alone application to terminate for as 
> long as 60 sec
> --
>
> Key: LOG4J2-1748
> URL: https://issues.apache.org/jira/browse/LOG4J2-1748
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Appenders
>Affects Versions: 2.7
> Environment: Java8, Windows
>Reporter: Daniele Demichelis
>  Labels: RollingFile, bug
>
> This code reproduces what I think is a bug of Log4j2.
> It's a simple loop that logs 2000 messages with two appenders:
> a console appender and a rolling file appender that rolls the file
> every 5Kb. This limit is intentionally low to reproduce what I think is a bug.
> Here's the code.
> {code:java}
> package bug;
> 
> import org.apache.logging.log4j.LogManager;
> import org.apache.logging.log4j.Logger;
> 
> public class Example {
> 
> private static final Logger logger = 
> LogManager.getLogger(Example.class);
> 
> public static void main(String[] args) throws InterruptedException {
> for(int i = 0; i<2000; i++){
> logger.info("This is log message #{}.", i);
> Thread.sleep(0);
> }
> }
> 
> }
> {code}
> Here's the `log4j2.xml` configuration file.
> {code:xml}
> 
> 
> 
> 
> 
> 
>   fileName="target/log4j2/roll-by-size/app.log"
>  
> filePattern="target/log4j2/roll-by-size/app.%i.log.gz"
>  ignoreExceptions="false"
>  append="false">
> 
> %d{-MM-dd HH:mm:ss} %p %m%n
> 
> 
> 
>  size="5 KB"/>
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> 
> {code}
> What is strange is that when the application is launched you will see this 
> logs in the console.
> {code}
> 2016-12-22 22:12:36 INFO This is log message #1993.
> 2016-12-22 22:12:36 INFO This is log message #1994.
> 2016-12-22 22:12:36 INFO This is log message #1995.
> 2016-12-22 22:12:36 INFO This is log message #1996.
> 2016-12-22 22:12:36 INFO This is log message #1997.
> 2016-12-22 22:12:36 INFO This is log message #1998.
> 2016-12-22 22:12:36 INFO This is log message #1999.
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]
> 2016-12-22 22:13:36,380 pool-1-thread-1 DEBUG Stopping 
> LoggerContext[name=60199c81, 
> org.apache.logging.log4j.core.LoggerContext@4597ec68]...
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=StatusLogger]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 1 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=ContextSelector]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Loggers,name=bug, 
> org.apache.logging.log4j2:type=60199c81,component=Lo
> ggers,name=]
> 2016-12-22 22:13:36,381 pool-1-thread-1 TRACE Unregistering 2 MBeans: 
> [org.apache.logging.log4j2:type=60199c81,component=Appenders,name=roll-by-size,
>  org.apache.logging.log4j2:type=60199c81,c
> omponent=Appenders,name=stdout]
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncAppenders,name=*'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=AsyncLoggerRingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Unregistering but no MBeans 
> found matching 
> 'org.apache.logging.log4j2:type=60199c81,component=Loggers,name=*,subtype=RingBuffer'
> 2016-12-22 22:13:36,382 pool-1-thread-1 TRACE Stopping 
>