[BUG] Slf4j/Log4j2 Log Argument Formatting

[AndreKurait]

What is the bug?

Currently, when running the replayer, Log4j2 outputs Unable to format msg along with java.lang.IllegalArgumentException: found 1 argument placeholders, but provided 0 for pattern

How can one reproduce the bug?

I've created unit tests to simulate the behavior in various instances. Including it here below: As you can see, it happens whenever objects are included in the "setMessage" function, but not when placed in the addArgument.

package org.opensearch.migrations.replay;

import java.util.ArrayList;
import java.util.Collections;
import java.util.List;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.appender.AbstractAppender;
import org.apache.logging.log4j.core.impl.Log4jContextFactory;
import org.apache.logging.log4j.core.selector.ClassLoaderContextSelector;
import org.apache.logging.log4j.status.StatusData;
import org.apache.logging.log4j.status.StatusListener;
import org.apache.logging.log4j.status.StatusLogger;
import org.junit.jupiter.api.Assertions;
import org.junit.jupiter.api.Test;
import org.slf4j.LoggerFactory;

class LoggingTest {
    static {
        // Synchronize logging for assertions
        LogManager.setFactory(new Log4jContextFactory(new ClassLoaderContextSelector()));
    }

    @Test
    public void testLogInline_internalLoggerError() {
        try (var closeableLogSetup = new CloseableLogSetup()) {
            closeableLogSetup.testLogger.atInfo().setMessage("hello {} hello").log();
            Assertions.assertEquals(1, closeableLogSetup.logEvents.size());

            var contents = closeableLogSetup.logEvents.get(0);
            Assertions.assertEquals("hello {} hello", contents);

            var errorContents = closeableLogSetup.errorEvents.get(0);
            System.err.println(errorContents);
            Assertions.assertTrue(errorContents.contains("Unable to format msg") && errorContents.contains("java.lang.IllegalArgumentException"));
        }
    }

    @Test
    public void testLogSupplier_internalLoggerError() {
        try (var closeableLogSetup = new CloseableLogSetup()) {
            closeableLogSetup.testLogger.atInfo().setMessage(() -> "hello {} hello").log();
            Assertions.assertEquals(1, closeableLogSetup.logEvents.size());

            var contents = closeableLogSetup.logEvents.get(0);
            Assertions.assertEquals("hello {} hello",contents);

            var errorContents = closeableLogSetup.errorEvents.get(0);
            System.err.println(errorContents);
            Assertions.assertTrue(errorContents.contains("Unable to format msg") && errorContents.contains("java.lang.IllegalArgumentException"));
        }
    }

    @Test
    public void testLogArgument_works() {
        try (var closeableLogSetup = new CloseableLogSetup()) {
            closeableLogSetup.testLogger.atInfo().setMessage("{}").addArgument(() -> "hello {} hello").log();
            Assertions.assertEquals(1, closeableLogSetup.logEvents.size());

            var contents = closeableLogSetup.logEvents.get(0);
            Assertions.assertEquals("hello {} hello",contents);
            Assertions.assertEquals(0, closeableLogSetup.errorEvents.size());
        }
    }

    private static class CloseableLogSetup implements AutoCloseable {
        List<String> logEvents = Collections.synchronizedList(new ArrayList<>());
        List<String> errorEvents = Collections.synchronizedList(new ArrayList<>());
        AbstractAppender testAppender;
        StatusListener testStatusListener;
        org.slf4j.Logger testLogger;
        org.apache.logging.log4j.core.Logger internalLogger;

        final String instanceName;

        public CloseableLogSetup() {
            instanceName = this.getClass().getName() + ".Thread" + Thread.currentThread().getId();

            testAppender = new AbstractAppender(instanceName,
                null, null, false, null) {
                @Override
                public void append(LogEvent event) {
                        logEvents.add(event.getMessage().getFormattedMessage());
                }
            };

            testAppender.start();

            internalLogger = (org.apache.logging.log4j.core.Logger) LogManager.getLogger(instanceName);
            testLogger = LoggerFactory.getLogger(instanceName);

            // Cast to core.Logger to access internal methods
            internalLogger.setLevel(Level.ALL);
            internalLogger.setAdditive(false);
            internalLogger.addAppender(testAppender);

            testStatusListener = new StatusListener() {
                @Override
                public void log(StatusData data) {
                    errorEvents.add(data.getMessage().getFormattedMessage() + "$$$" + data.getMessage().getThrowable().toString());
                }

                @Override
                public Level getStatusLevel() {
                    return Level.ERROR;
                }

                @Override
                public void close() {
                    // No Op
                }
            };
            StatusLogger.getLogger().registerListener(testStatusListener);
        }

        @Override
        public void close() {
            internalLogger.removeAppender(testAppender);
            testAppender.stop();
            StatusLogger.getLogger().removeListener(testStatusListener);
        }
    }

}

What is the expected behavior?

No error message, objects tostring is included in the log without additional parameterization

What is your host/environment?

Java Coretto 11, MacOS M1 Pro Arm64

Do you have any screenshots?

N/A

Do you have any additional context?

N/A

[AndreKurait]

I've created a PR fixing these errors by moving the log syntax to .addArgument. Seeking feedback from others on other solutions #632

[AndreKurait]

Here's a page on Log4j's page discussing how string concatenation like we currently use it may be vulnerable to attacks

https://github.com/apache/logging-log4j2/blob/2.x/src/site/antora/modules/ROOT/pages/5min.adoc#dont-use-string-concatenation

[AndreKurait]

Furthermore, consider

I'd like to see us pull back the disruptor changes altogether & even just switching to WARN for everything other than progressLogging, tupleLogging, and longRunningActivity logging.

#634 (review)

[gregschohn]

Added to Migration’s Team Backlog - Refer to the Jira issue for more details.