[LOG4J2-2118] MutableLogEvent does not retain the Message format string

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.8
• Fix Version/s: 2.11.0
• Component/s: Layouts
• Labels: layout

Environment

Mac OS X 10.11.6
Java 1.8.0_141

• Assignee: Remko Popma
• Reporter: Zack Slayton
• Created: 13/Nov/17 23:10
• Updated: 29/Jul/20 07:37
• Resolved: 27/Feb/18 03:56

Description

I'm attempting to create a custom binary Layout that stores the provided format string separate from the parameters rather than eagerly formatting them all into a single piece of text. However, when I went to implement `Layout::toByteArray`, I discovered that the `Message::getFormat` method always returns null.

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginFactory;
import org.apache.logging.log4j.core.layout.AbstractLayout;

import java.io.Serializable;
import java.util.Arrays;

@Plugin(name = "MyLayout", category = "Core", elementType = "layout", printObject = true)
public class MyLayout extends AbstractLayout {

    public MyLayout() {
        super(null, null, null);
    }

    @PluginFactory
    public static MyLayout createLayout(){
        return new MyLayout();
    }

    public static void main(String[] args) {
        Logger log = LogManager.getLogger(MyLayout.class);
        log.info("Here's a thing: {}. And another: {}", 75, "walrus");
    }

    @Override
    public byte[] toByteArray(LogEvent event) {
        System.out.println("Format: " + event.getMessage().getFormat());
        System.out.println("Parameters: " + Arrays.toString(event.getMessage().getParameters()));
        return new byte[0];
    }

    @Override
    public Serializable toSerializable(LogEvent event) {
        return null;
    }

    @Override
    public String getContentType() {
        return null;
    }

    @Override
    public byte[] getFooter() {
        return new byte[0];
    }

    @Override
    public byte[] getHeader() {
        return new byte[0];
    }
}

If I run `main` (with an extra `PatternLayout`+`Console` appender in my config), I see the following output:

17:55:28.524 [main] INFO  com.example.logging.plugins.MyLayout - Here's a thing: 75. And another: walrus
Format: null
Parameters: [75, walrus]

I had expected to be able to see the format string and the array of parameters, but instead I can only see the parameters. The format string is always null.

This appears to be due to the implementation of `MutableLogEvent::setMessage` highlighted in LOG4J2-1510. Because the messages are reusable, they appear to be eagerly formatted and the format string itself is discarded. The `getFormat` method is hardcoded to return `null`.

Is this by design? If so, what is the prescribed approach to getting the format string in my layout? (Preferably one that does not disable the performance optimizations offered by enabling threadlocals.)

Thanks!

Issue Links

• duplicates: LOG4J2-2252 Reusable events drop the original format string
• links to: GitHub Pull Request #131
• links to: GitHub Pull Request #131