Java logging - MDC.put delay?

Question

I'm trying to setup some logging. Specification is to have separate logs per ip. Let's forget large number of files for now. In my logback.xml I have:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <property name="LOG_MAIN_FOLDER" value="./log/sifting" />

    <appender name="FILE-THREAD" class="ch.qos.logback.classic.sift.SiftingAppender">
        <!-- This is MDC value -->
        <!-- We will assign a value to 'logFileName' via Java code -->
        <discriminator>
            <key>logFileName</key>
            <defaultValue>head0</defaultValue>
        </discriminator>

        <sift>

          <!-- A standard RollingFileAppender, the log file is based on 'logFileName' at runtime  -->
          <appender name="FILE-${logFileName}" class="ch.qos.logback.core.rolling.RollingFileAppender">
-           <file>${LOG_MAIN_FOLDER}/${logFileName}.log</file>

            <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
                <Pattern>
                    %d{yyyy-MM-dd HH:mm:ss} %mdc [%thread] %level %logger{35} - %msg%n
                </Pattern>
            </encoder>

            <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
                <FileNamePattern>${LOG_MAIN_FOLDER}/${logFileName}.%i.log.zip</FileNamePattern>
                <MinIndex>1</MinIndex>
                <MaxIndex>10</MaxIndex>
            </rollingPolicy>

            <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
                <MaxFileSize>10MB</MaxFileSize>
            </triggeringPolicy>
          </appender>
        </sift>
    </appender>

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>
                %-5level %logger{36} - %msg%n
            </Pattern>
        </layout>
    </appender>

    <logger name="poc.log.SiftingLog" level="debug" additivity="false">
        <appender-ref ref="FILE-THREAD" />
        <appender-ref ref="STDOUT" />
    </logger>

    <root level="error">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

And here is my code:

private void runTest() {
    for (int threadNo = 0; threadNo < 100; threadNo++) {
        new Thread(() -> {
            StringJoiner ip = new StringJoiner(".");
            for (int i = 0; i < 4; i++) ip.add(new Random().nextInt(256) + "");
            
            Logger logger = LoggerFactory.getLogger(SiftingLog.class);
            MDC.put("logFileName", getPathName(ip.toString()));
            logger.info(MDC.getCopyOfContextMap().get("logFileName"));
            
            
            logger.debug("hello " + ip.toString());
            try {Thread.sleep(200);} catch (InterruptedException e) {}
            logger.debug("working " + ip.toString());
            try {Thread.sleep(200);} catch (InterruptedException e) {}
            logger.debug("bye " + ip.toString());

            //remember remove this
            MDC.remove("logFileName");
        }).start();
    }
}

I want all the logs to be placed in ip-named files. However head0 log file is being created and all the threads put first two lines (.info and .debug of 'hello') in default log file. After sleeping some time next two debug lines are placed all correct.

How can I flush MDC.put command? I have chosen slf4j and SiftingLogger because it was easiest to find any tutorials/information around. If any other library or tools are better for this task, please tell me.

Answer 1

Make logger a constant instead of initializing it in every thread, see if that helps.

private static final Logger logger = LoggerFactory.getLogger(SiftingLog.class);