LOG4J: Modify logged message using custom appender

Question

For security reasons, I need to look at every logged message in my app and possibly modify it before it goes to the log file. I figured I could write a custom appender (extending DailyRollingFileAppender) and override subAppend(LoggingEvent event). Problem is, there's no setter for the message text in LoggingEvent, and the message is a private attribute. I could create a new LoggingEvent with my modified message, but the API doesn't make it easy to copy over the rest of the original LoggingEvent. It all seems designed to discourage meddling with the message in a custom appender.

The only other option I can see is to modify hundreds of logging statements to call a new global method that can modify the text first and then make the Log4J call. I'd rather not!

Has anyone else had the need to modify the logged message in a custom appender?

Answer 1

I'm not entirely sure why creating a new LoggingEvent is so onerous. This seems to work for me:

package test.logging;

import org.apache.log4j.DailyRollingFileAppender;
import org.apache.log4j.spi.LoggingEvent;

public class MyDailyRollingFileAppender extends DailyRollingFileAppender {

    @Override
    protected void subAppend(LoggingEvent event) {
        String modifiedMessage = String.format("**** Message modified by MyDailyRollingFileAppender ****\n\n%s\n\n**** Finished modified message ****", event.getMessage());
        LoggingEvent modifiedEvent = new LoggingEvent(event.getFQNOfLoggerClass(), event.getLogger(), event.getTimeStamp(), event.getLevel(), modifiedMessage,
                                                      event.getThreadName(), event.getThrowableInformation(), event.getNDC(), event.getLocationInformation(),
                                                      event.getProperties());

        super.subAppend(modifiedEvent);
    }

}

With this test:

package test;

import org.apache.log4j.Logger;

public class TestLogging {

    public static void main(String[] args) {
        Logger log = Logger.getLogger(TestLogging.class);
        log.info("I am testing my logging");
        log.info("Here is an exception", new Exception());
    }

}

and this configuration:

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">

    <appender name="MyDailyRollingFileAppender" class="test.logging.MyDailyRollingFileAppender">
        <param name="Append" value="true"/>
        <param name="datePattern" value="'.'yyyy-MM-dd"/>
        <param name="File" value="mine.log"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d %-5p (%x) [%t] %c{1} - %m%n" />
        </layout>
    </appender>

    <root>
        <priority value="debug"/>
        <appender-ref ref="MyDailyRollingFileAppender"/>
    </root>

</log4j:configuration>

I am getting the following output:

2011-10-14 10:09:09,322 INFO  () [main] TestLogging - **** Message modified by MyDailyRollingFileAppender ****

I am testing my logging

**** Finished modified message ****
2011-10-14 10:09:09,333 INFO  () [main] TestLogging - **** Message modified by MyDailyRollingFileAppender ****

Here is an exception

**** Finished modified message ****
java.lang.Exception
    at test.TestLogging.main(TestLogging.java:10)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:120)

Although I have done something similar to this, I used a slightly different approach. Instead of writing subclasses of each type of Appender I wanted to use, I created an Appender which wraps other Appender objects, and modifies the message before sending to the wrapped Appenders. Something like this:

package test.logging;

import org.apache.log4j.Appender;
import org.apache.log4j.AppenderSkeleton;
import org.apache.log4j.spi.AppenderAttachable;
import org.apache.log4j.spi.LoggingEvent;

import java.util.ArrayList;
import java.util.Collections;
import java.util.Enumeration;
import java.util.Iterator;
import java.util.List;

public class MyAppenderWrapper extends AppenderSkeleton implements AppenderAttachable {

    private final List<Appender> appenders = new ArrayList<Appender>();

    public void close() {
        synchronized (appenders) {
            for (Appender appender : appenders) {
                appender.close();
            }
        }
    }

    public boolean requiresLayout() {
        return false;
    }

    public void addAppender(Appender appender) {
        synchronized (appenders) {
            appenders.add(appender);
        }
    }

    public Enumeration getAllAppenders() {
        return Collections.enumeration(appenders);
    }

    public Appender getAppender(String name) {
        synchronized (appenders) {
            for (Appender appender : appenders) {
                if (appender.getName().equals(name)) {
                    return appender;
                }
            }
        }
        return null;
    }

    public boolean isAttached(Appender appender) {
        synchronized (appenders) {
            for (Appender wrapped : appenders) {
                if (wrapped.equals(appender)) {
                    return true;
                }
            }
            return false;
        }
    }

    public void removeAllAppenders() {
        synchronized (appenders) {
            appenders.clear();
        }
    }

    public void removeAppender(Appender appender) {
        synchronized (appenders) {
            for (Iterator<Appender> i = appenders.iterator(); i.hasNext(); ) {
                if (i.next().equals(appender)) {
                    i.remove();
                }
            }
        }
    }

    public void removeAppender(String name) {
        synchronized (appenders) {
            for (Iterator<Appender> i = appenders.iterator(); i.hasNext(); ) {
                if (i.next().getName().equals(name)) {
                    i.remove();
                }
            }
        }
    }

    @Override
    protected void append(LoggingEvent event) {
        String modifiedMessage = String.format("**** Message modified by MyAppenderWrapper ****\n\n%s\n\n**** Finished modified message ****", event.getMessage());
        LoggingEvent modifiedEvent = new LoggingEvent(event.getFQNOfLoggerClass(), event.getLogger(), event.getTimeStamp(), event.getLevel(), modifiedMessage,
                                                      event.getThreadName(), event.getThrowableInformation(), event.getNDC(), event.getLocationInformation(),
                                                      event.getProperties());

        synchronized (appenders) {
            for (Appender appender : appenders) {
                appender.doAppend(modifiedEvent);
            }
        }
    }

}

Which you could configure like:

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">

    <appender name="StdOut" class="org.apache.log4j.ConsoleAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d %-5p (%x) [%t] %c{1} - %m%n" />
        </layout>
    </appender>

    <appender name="FileAppender" class="org.apache.log4j.DailyRollingFileAppender">
        <param name="Append" value="true"/>
        <param name="datePattern" value="'.'yyyy-MM-dd"/>
        <param name="File" value="mine.log"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d %-5p (%x) [%t] %c{1} - %m%n" />
        </layout>
    </appender>

    <appender name="AppenderWrapper" class="test.logging.MyAppenderWrapper">
        <appender-ref ref="StdOut"/>
        <appender-ref ref="FileAppender"/>
    </appender>

    <root>
        <priority value="debug"/>
        <appender-ref ref="AppenderWrapper"/>
    </root>

</log4j:configuration>

That way the message is still sent to the original appenders but with the modified message.

Answer 2

Thats how I did since I am working with an older version of log4j

Instead of customizing appender, I customized the layout and referred that layout in whichever Appender i needed this feature

public class LogValidatorLayout extends PatternLayout {

    public LogValidatorLayout() {
        super();
    }

    public LogValidatorLayout(String pattern) {
        super(pattern);
    }

    @Override
    public String format(LoggingEvent event) {

        // only process String type messages
        if (event.getMessage() != null && event.getMessage() instanceof String) {

            String message = event.getMessage().toString();
            message = StringUtils.trim("Some custom text --->>"+message);

            // earlier versions of log4j don't provide any way to update messages,
            // so use reflections to do this
            try {
                Field field = LoggingEvent.class.getDeclaredField("message");
                field.setAccessible(true);
                field.set(event, message);
            } catch (Exception e) {
                // Dont log it as it will lead to infinite loop. Simply print the trace
                e.printStackTrace();
            }

        }

        return super.format(event);
    }

}

And in your log4j.properties or xml, register this Layout

log4j.appender.STDOUT.layout=a.b.c.package.LogValidatorLayout

Answer 3

Another option is to customize the Layout used by your appender. Since layout is responsible for serializing log event to a string, I'd check if twitching the layout is less complicated than changing the appender and events going through. Just an idea...