You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@logging.apache.org by "Libor Svehlak (Jira)" <ji...@apache.org> on 2019/11/01 16:53:00 UTC

[jira] [Created] (LOG4J2-2717) Slow initialization under Windows

Libor Svehlak created LOG4J2-2717:
-------------------------------------

             Summary: Slow initialization under Windows
                 Key: LOG4J2-2717
                 URL: https://issues.apache.org/jira/browse/LOG4J2-2717
             Project: Log4j 2
          Issue Type: Bug
          Components: Core
    Affects Versions: 2.12.1, 2.12.0
         Environment: Tested JDKs:

* jdk1.8.0_221
* jdk-9.0.4
* jdk-11.0.4
* jdk-12.0.2
* jdk-13.0.1

Tested OS: Windows 10 1809
            Reporter: Libor Svehlak


Together with feature LOG4J2-913 (included in 2.12.0) was introduced in commit cb905f37c1ec10e8aa7637dd9770e3cf4672c830 (https://gitbox.apache.org/repos/asf?p=logging-log4j2.git;h=cb905f3) following change in the file {{WatchManager.java}} (https://gitbox.apache.org/repos/asf?p=logging-log4j2.git;a=blob;f=log4j-core/src/main/java/org/apache/logging/log4j/core/util/WatchManager.java;h=3e3715258b498a55247e52d1cc360a91f5681a8f;hb=cb905f3):

{code:java}
private final UUID id = UuidUtil.getTimeBasedUuid();
{code}

This change is causing that during log4j2 initialization are enumerated network interfaces (seems to be quite slow operation under Windows).

Behavior can be reproduced with the simple test program:

{code:java}
package test;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class TestLog4j2Startup {
    public static void main(String[] args) {
        System.out.println("Test started");

        System.out.println("Starting to initialize the logger");
        long startTime = System.currentTimeMillis();
        Logger logger = LogManager.getLogger();
        long endTime = System.currentTimeMillis();
        System.out.println("Logger initialization took " + (endTime - startTime) + " ms");

        logger.info("Hello from log4j2!");

        System.out.println("Test finished");
    }
}
{code}

Execution of the following command then prints how much time initialization takes:

{{java -cp .;log4j-api-2.12.1.jar;log4j-core-2.12.1.jar test.TestLog4j2Startup}}

Delay is depending on number of enabled network interfaces. In our case delay in the initialization is between 5 to 10 seconds.

The same command with log4j2 version 2.11.2 is executed as expected (within few hundreds of milliseconds).

Suggested solution: Late initialization of the {{id}} field or different mechanism how {{id}} is generated.



--
This message was sent by Atlassian Jira
(v8.3.4#803005)