You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Remko Popma (JIRA)" <ji...@apache.org> on 2015/08/17 14:53:46 UTC

[jira] [Updated] (LOG4J2-1094) Multi thread initialization problem

     [ https://issues.apache.org/jira/browse/LOG4J2-1094?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Remko Popma updated LOG4J2-1094:
--------------------------------
    Description: 
I wrote a very simple example which has a behaviour I do not expect:

If I call LogManager.getLogger(..) from two threads, only one of the loggers logs what I'd expect but if I add an additional call to LogManager.getLogger(..) before the threads are started, I see what I'd expect so it looks like there is a problem in multi threaded initialization.

You can find the code and the configuration here:

- https://github.com/lburgazzoli/lb-chronicle/blob/master/chronicle-examples/chronicle-logger-log4j2/src/main/java/com.github.lburgazzoli.openhft.examples.chronicle.logger.log4j2/MtLogging.java
- https://github.com/lburgazzoli/lb-chronicle/blob/master/chronicle-examples/chronicle-logger-log4j2/src/main/resources/log4j2.xml

{code}
public class MtLogging {
    public static void main(final String[] args) throws Exception {
        //LogManager.getLogger("main");

        Thread th1 = new Thread(() -> {
            final String name = "thread-1";
            final Logger log = LogManager.getLogger(name);
            System.out.println("write " + name);
            log.info("message");
            System.out.println("done " + name);
        });

        Thread th2 = new Thread(() -> {
            final String name = "thread-2";
            final Logger log = LogManager.getLogger(name);
            System.out.println("write " + name);
            log.info("message");
            System.out.println("done " + name);
        });

        th1.start();
        th2.start();
        th1.join();
        th2.join();
    }
}
{code}

{code}
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appenders>
        <Console name="STDOUT" target="SYSTEM_OUT">
            <PatternLayout pattern="[TEST] [%-5p] %c - %m%n%throwable{none}"/>
        </Console>
    </appenders>
    <loggers>
        <root level="all">
            <appender-ref ref="STDOUT"/>
        </root>
    </loggers>
</configuration>
{code}

The code above will show:

{noformat}
    write thread-1
    done thread-1 
    write thread-2
    [TEST] [INFO ] thread-2 - message
    done thread-2
{noformat}

Any call to LogManager makes it succeed:

{code}
    LogManager.getContext(false);
    th1.start();
    th2.start();
    th1.join();
    th2.join();
{code}

New output:

{noformat}
    write thread-2
    write thread-1
    [TEST] [INFO ] thread-2 - message
   done thread-2
   [TEST] [INFO ] thread-1 - message
   done thread-1
{noformat}

The funny thing is that the first thread to arrive is initialized with ERROR level instead of the ALL that is given to root. In other words it seems that the config has not loaded


  was:
I wrote a very simple example which has a behaviour I do not expect:

If I call LogManager.getLogger(..) from two threads, only one of the loggers logs what I'd expect but if I add an additional call to LogManager.getLogger(..) before the threads are started, I see what I'd expect so it looks like there is a problem in multi threaded initialization.

You can fine the code and the configuration here:

- https://github.com/lburgazzoli/lb-chronicle/blob/master/chronicle-examples/chronicle-logger-log4j2/src/main/java/com.github.lburgazzoli.openhft.examples.chronicle.logger.log4j2/MtLogging.java
- https://github.com/lburgazzoli/lb-chronicle/blob/master/chronicle-examples/chronicle-logger-log4j2/src/main/resources/log4j2.xml

The code above will show:

{noformat}
    write thread-1
    done thread-1 
    write thread-2
    [TEST] [INFO ] thread-2 - message
    done thread-2
{noformat}

Any call to LogManager makes it succeed:

{code}
    LogManager.getContext(false);
    th1.start();
    th2.start();
    th1.join();
    th2.join();
{code}

New output:

{noformat}
    write thread-2
    write thread-1
    [TEST] [INFO ] thread-2 - message
   done thread-2
   [TEST] [INFO ] thread-1 - message
   done thread-1
{noformat}

The funny thing is that the first thread to arrive is initialized with ERROR level instead of the ALL that is given to root. In other words it seems that the config has not loaded



> Multi thread initialization problem
> -----------------------------------
>
>                 Key: LOG4J2-1094
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1094
>             Project: Log4j 2
>          Issue Type: Bug
>    Affects Versions: 2.3
>            Reporter: Luca Burgazzoli
>
> I wrote a very simple example which has a behaviour I do not expect:
> If I call LogManager.getLogger(..) from two threads, only one of the loggers logs what I'd expect but if I add an additional call to LogManager.getLogger(..) before the threads are started, I see what I'd expect so it looks like there is a problem in multi threaded initialization.
> You can find the code and the configuration here:
> - https://github.com/lburgazzoli/lb-chronicle/blob/master/chronicle-examples/chronicle-logger-log4j2/src/main/java/com.github.lburgazzoli.openhft.examples.chronicle.logger.log4j2/MtLogging.java
> - https://github.com/lburgazzoli/lb-chronicle/blob/master/chronicle-examples/chronicle-logger-log4j2/src/main/resources/log4j2.xml
> {code}
> public class MtLogging {
>     public static void main(final String[] args) throws Exception {
>         //LogManager.getLogger("main");
>         Thread th1 = new Thread(() -> {
>             final String name = "thread-1";
>             final Logger log = LogManager.getLogger(name);
>             System.out.println("write " + name);
>             log.info("message");
>             System.out.println("done " + name);
>         });
>         Thread th2 = new Thread(() -> {
>             final String name = "thread-2";
>             final Logger log = LogManager.getLogger(name);
>             System.out.println("write " + name);
>             log.info("message");
>             System.out.println("done " + name);
>         });
>         th1.start();
>         th2.start();
>         th1.join();
>         th2.join();
>     }
> }
> {code}
> {code}
> <?xml version="1.0" encoding="UTF-8"?>
> <configuration>
>     <appenders>
>         <Console name="STDOUT" target="SYSTEM_OUT">
>             <PatternLayout pattern="[TEST] [%-5p] %c - %m%n%throwable{none}"/>
>         </Console>
>     </appenders>
>     <loggers>
>         <root level="all">
>             <appender-ref ref="STDOUT"/>
>         </root>
>     </loggers>
> </configuration>
> {code}
> The code above will show:
> {noformat}
>     write thread-1
>     done thread-1 
>     write thread-2
>     [TEST] [INFO ] thread-2 - message
>     done thread-2
> {noformat}
> Any call to LogManager makes it succeed:
> {code}
>     LogManager.getContext(false);
>     th1.start();
>     th2.start();
>     th1.join();
>     th2.join();
> {code}
> New output:
> {noformat}
>     write thread-2
>     write thread-1
>     [TEST] [INFO ] thread-2 - message
>    done thread-2
>    [TEST] [INFO ] thread-1 - message
>    done thread-1
> {noformat}
> The funny thing is that the first thread to arrive is initialized with ERROR level instead of the ALL that is given to root. In other words it seems that the config has not loaded



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org