log4j2: Location for setting Log4jContextSelector system property for asynchronous logging

Question

I am attempting to set up asynchronous logging (for performance reasons) within REST web methods that currently run in a liberty profile server.

In order to do this, I have set up the following property:

System.setProperty("Log4jContextSelector", "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector");

My problem is that no matter where I do this, sometimes it works and logging is very fast, and sometimes it doesn't.

I have tried (a) in the constructor for the class containing all the REST web methods (b) in the filter doFilter method that gets called prior to the REST method (c) in the filter init method (d) in the REST method itself

None of these locations work consistently.

Can anyone offer an explanation for this behaviour, and if possible a suggested way of fixing the problem.

EDIT: It appears that log4j is being initialised prior to calling setProperty. So what I need to do is set up the property via liberty profile instead.

Inquiline

@fnt No, I don't have proof, didn't make comparisions, so I'll change my comment. I just have comparison to standard logging here Binary logging performance - slide 23. – Bomb

You may evaluate binary logging option in Liberty as it has better performance than standard logging. Maybe it will be good enough for you. – Bomb

Good read. springframework.guru/asynchronous-logging-with-log4j-2 – Description

It seems that Log4J2 supports this feature using the property name log4j2.contextSelector as well as Log4JContextSelector - and the documentation seems to mix the two in places. – Outclass

Answer 1

There is an undocumented method of setting this value for your project without having to manually pass in the system property value during start up.

Add a file named log4j2.component.properties to your classpath. This can be done in most maven or gradle projects by saving it in src/main/resources.

This is file is simply java.util.Properties file. Set the value for the context selector by adding the following line to the file.

Log4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

Log4j will attempt to read the system property first. If the system property is null, then it will fall back to the values stored in this file by default.

The code that performs this setup is located at Log4jContextFactory.java:91.

Padishah

Is there anything I could do to verify this property is taken into account if added as file? Sidenote: the filename can nowadays be seen in org.apache.logging.log4j.util.PropertiesUtil.LOG4J_PROPERTIES_FILE_NAME. – Skipton

That was super - helpful. Thanks, any idea how to contribute back to the log4j documentation? If I had had that info it would probably saved me some hours searching. – Pauper

Answer 2

My problem is that no matter where I do this, sometimes it works and logging is very fast, and sometimes it doesn't.

Add that code in a static initializer block in the class that defines your main entry point.

public class MainClass {
    // NOTE: Nothing can appear before this initializer
    // NOTE: This initializer must be in the class that contains your entry point
    static {
        System.setProperty("Log4jContextSelector",
            "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector");
    }

    public static void main(final String[] args) {
        // Do anything you want to here
    }
}

According to the Java specification, static initialization occurs in the order it is declared. Therefore, the System.setProperty call is guaranteed to happen before the Log4j initialization.

Isacco

Answer 3

So apparently I needed to add a line to the jvm.options file

-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

The jvm.options file is located here:

${server.config.dir}/jvm.options

And that directory can be found by using the link:

http://www-01.ibm.com/support/knowledgecenter/SSEQTP_8.5.5/com.ibm.websphere.wlp.doc/ae/rwlp_dirs.html?cp=SSEQTP_8.5.5%2F1-3-11-0-2-0

In my case it is at: C:\eclipse\runtime\usr\servers\serverName

Inquiline

Will it work if it is added to VM arguments of server configuration for Tomcat? – Wardmote

Answer 4

Log4j got initialized before calling the main method. So it's unable to pick your property Log4jContextSelector from the system and by default, it works synchronously.

To verify same: remove disruptor dependency, If your project is still going up then it's not getting async.

If you add property via -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector then after removing disruptor project will not go up.

If you are using tomcat then add system properties in catalina.properties. And don't forget to use immediateFlush="false".

Reef