java (log4j) logging filter by object type

问题:

I have a logging statement currently implemented with log4j:

log.info("Failed to create message for {}", CustomerData);

This will log some sensitive data in CustomerData.

Is there a way to block logging of any instances of CustomerData? Maybe in log4j configuration or via a custom filter?

If not possible with log4j, how about other logging frameworks?

回答1:

Log4j2 offers a number of ways to accomplish this:

Filters

Log4j2 allows you to configure filters on specific loggers, or on specific appenders, or globally (so the filter applies to all log events). What filters give you is the ability to force-ACCEPT a log event, or force-DENY a log event, or to be "NEUTRAL". In your case you may want to DENY log events that contain sensitive data.

You can create a custom Filter implementation (see the plugin docs for how to install your custom filter), or you can use some of the built-in filters. Either the built-in RegexFilter or a ScriptFilter should be sufficient for your purposes.

Regex filter example

Let's say that this is a class that contains sensitive data:

public class Customer {
    public String name;
    public String password;

    @Override
    public String toString() {
        return "Customer[name=" + name + ", password=" + password + "]";
    }
}

And your application logging looks something like this:

public class CustomerLoggingApp {
    public static void main(String[] args) {
        Logger log = LogManager.getLogger();

        Customer customer = new Customer();
        customer.name = "Jesse Zhuang";
        customer.password = "secret123";

        log.info("This is sensitive and should not be logged: {}", customer);
        log.info("But this message should be logged.");
    }
}

You can configure a regex filter that looks at the formatted (or unformatted) message and DENY any log messages that have the word "Customer" followed by ", password=" in them:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <RegexFilter regex=".*Customer.*, password=.*" onMatch="DENY" onMismatch="NEUTRAL"/>
      <PatternLayout>
        <pattern>%d %level %c %m%n</pattern>
      </PatternLayout>
    </Console>
  </Appenders>
  <Loggers>
    <Root level="debug">
      <AppenderRef ref="Console" />
    </Root>
  </Loggers>
</Configuration>

Script filter example

Another very flexible filter is ScriptFilter. The below example uses Groovy, but you can also use JavaScript or whatever other scripting language is available on your Java installation.

Given the above application classes, the following log4j2.xml configuration would filter out any log events containing any parameters whose fully qualified class name is Customer:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn">
  <ScriptFilter onMatch="DENY" onMisMatch="NEUTRAL">
    <Script name="DropSensitiveObjects" language="groovy"><![CDATA[
                parameters.any { p ->
                    // DENY log messages with Customer parameters
                    p.class.name == "Customer"
                }
              ]]>
    </Script>
  </ScriptFilter>
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout>
        <pattern>%d %level %c %m%n</pattern>
      </PatternLayout>
    </Console>
  </Appenders>
  <Loggers>
    <Root level="debug">
      <AppenderRef ref="Console" />
    </Root>
  </Loggers>
</Configuration>

Rewriting Log Events

Another interesting option is to rewrite the log event so that the message does not get completely filtered out, but instead you just mask the sensitive data. For example you replace the password string with "***" in the log.

To do this, you create a RewriteAppender. From the manual:

The RewriteAppender allows the LogEvent to manipulated before it is processed by another Appender. This can be used to mask sensitive information such as passwords or to inject information into each event.

Example rewrite policy:

package com.jesse.zhuang;

import org.apache.logging.log4j.core.Core;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.appender.rewrite.RewritePolicy;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginElement;
import org.apache.logging.log4j.core.config.plugins.PluginFactory;
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.message.ObjectMessage;
import org.apache.logging.log4j.message.ParameterizedMessage;
import org.apache.logging.log4j.message.ReusableMessage;

@Plugin(name = "MaskSensitiveDataPolicy", category = Core.CATEGORY_NAME, 
        elementType = "rewritePolicy", printObject = true)
public class MaskSensitiveDataPolicy implements RewritePolicy {

    private String[] sensitiveClasses;

    @PluginFactory
    public static MaskSensitiveDataPolicy createPolicy(
            @PluginElement("sensitive") final String[] sensitiveClasses) {
        return new MaskSensitiveDataPolicy(sensitiveClasses);
    }

    private MaskSensitiveDataPolicy(String[] sensitiveClasses) {
        super();
        this.sensitiveClasses = sensitiveClasses;
    }

    @Override
    public LogEvent rewrite(LogEvent event) {
        Message rewritten = rewriteIfSensitive(event.getMessage());
        if (rewritten != event.getMessage()) {
            return new Log4jLogEvent.Builder(event).setMessage(rewritten).build();
        }
        return event;
    }

    private Message rewriteIfSensitive(Message message) {
        // Make sure to switch off garbage-free logging
        // by setting system property `log4j2.enable.threadlocals` to `false`.
        // Otherwise you may get ReusableObjectMessage, ReusableParameterizedMessage
        // or MutableLogEvent messages here which may not be rewritable...
        if (message instanceof ObjectMessage) {
            return rewriteObjectMessage((ObjectMessage) message);
        }
        if (message instanceof ParameterizedMessage) {
            return rewriteParameterizedMessage((ParameterizedMessage) message);
        }
        return message;
    }

    private Message rewriteObjectMessage(ObjectMessage message) {
        if (isSensitive(message.getParameter())) {
            return new ObjectMessage(maskSensitive(message.getParameter()));
        }
        return message;
    }

    private Message rewriteParameterizedMessage(ParameterizedMessage message) {
        Object[] params = message.getParameters();
        boolean changed = rewriteSensitiveParameters(params);
        return changed ? new ParameterizedMessage(message.getFormat(), params) : message;
    }

    private boolean rewriteSensitiveParameters(Object[] params) {
        boolean changed = false;
        for (int i = 0; i < params.length; i++) {
            if (isSensitive(params[i])) {
                params[i] = maskSensitive(params[i]);
                changed = true;
            }
        }
        return changed;
    }

    private boolean isSensitive(Object parameter) {
        return parameter instanceof Customer;
    }

    private Object maskSensitive(Object parameter) {
        Customer result = new Customer();
        result.name = ((Customer) parameter).name;
        result.password = "***";
        return result;
    }
}

CAUTION: When running in garbage-free mode (the default), Log4j2 uses reusable objects for messages and log events. These are not suitable for rewriting. (This is not documented well in the user manual.) If you want to use the rewrite appender, you need to partially switch off garbage-free logging by setting system property log4j2.enable.threadlocals to false.

Configure your rewrite appender with your custom MaskSensitiveDataPolicy rewrite policy. To let Log4j2 know about your plugin, specify the name of the package of your plugin in the packages attribute of the Configuration:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" packages="com.jesse.zhuang">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout>
        <pattern>%d %level %c %m%n</pattern>
      </PatternLayout>
    </Console>

    <Rewrite name="obfuscateSensitiveData">
      <AppenderRef ref="Console"/>
      <MaskSensitiveDataPolicy />
    </Rewrite>

  </Appenders>
  <Loggers>
    <Root level="debug">
      <AppenderRef ref="obfuscateSensitiveData"/>
    </Root>
  </Loggers>
</Configuration>

This will make the above example program produce the following output. Note that the password is masked but other attributes of the sensitive object are preserved:

2018-01-09 22:18:30,561 INFO CustomerLoggingApp This is sensitive and should not be logged: Customer[name=Jesse Zhuang, password=***]
2018-01-09 22:18:30,569 INFO CustomerLoggingApp But this message should be logged.

回答2:

It is not (and probably will never be) provided in Log4j/SLF4j/whatever Logging framework.

In order to cope with your specific need, the easiest way is to have your own decorator of Logger.

It can be a custom logging implementation for SLF4J or Log4j2. Or simply some kind of factory for Logger (i.e. like LoggerFactory in SLF4j, or Logger.getLogger() for Log4j2)

It could internally create your custom Logger implementation, which delegates to the real logger, and you do extra checking in your logging impl.

e.g. (psuedo-code)

SensitiveDataCheckingLogger implements Logger {
    private Logger delegate;
    public SensitiveDataCheckingLogger(Logger delegate) {
        this.delegate = delegate;
    }

    @Override
    public void info (String message, Object... args) {
        if (delegate.infoEnabled()) {
            for (Object arg : args) {
                // or whatever way you want to check, e.g. by annotation 
                if (arg instanceof SenstiveData) {  
                    throw newOhNoSensitiveDataRuntimeException();
                }
            }

            delegate.info(message, args);
        }
    }
    // bunch of all other method implementations
}

public class MyLoggerFactory {
    Logger getLogger(Class<?> clazz) {
        return new SensitiveDataCheckingLogger(LoggerFactory.getLogger(clazz));
    }
}

so you just use it in similar way as before

Logger logger = MyLoggerFactory.getLogger(Foo.class);
...
logger.info("bablabla {}", sensitiveData);

---

But as you can see, there are a lot of drawbacks, like performance degrade.

---

If you are using Logback (I believe you can do similar for Log4j2 too), you may implement your own Appender, or Encoder etc.

When you log in Logback, it internally creates a log event, which contains the log message plus the parameters. So instead of actually formatting the log message in your appender (or encoder etc), you just do the parameters checking and throw exception if it does not look right.

Caution for this approach: - Appender is only reached if log level is enabled. Therefore if in config you set log level to WARN, then you won't be able to catch log message done by logger.info("message {}", senstive); - it has more to do with the internal implementation for the logging implementation you are using, which means it is harder to switch to other implementation (which is rare in real life I believe)

The advantage is, if you don't already have your own logging API, it helps to save code change as you can stick to SLF4J / Log4j2 APIs

---

Edit:

Just checked in Log4j2, it allow you to replace the MessageFactory (which is used to construct the message string based on message + params).

https://logging.apache.org/log4j/2.x/manual/extending.html

MessageFactory

A MessageFactory is used to generate Message objects. Applications may replace the standard ParameterizedMessageFactory (or ReusableMessageFactory in garbage-free mode) by setting the value of the system property log4j2.messageFactory to the name of the custom MessageFactory class.

Flow messages for the Logger.entry() and Logger.exit() methods have a separate FlowMessageFactory. Applications may replace the DefaultFlowMessageFactory by setting the value of the system property log4j2.flowMessageFactory to the name of the custom FlowMessageFactory class.

So, similar to above method, you can create your own MessageFactory which do extra param checking

回答3:

Easiest way to prevent this is to write/overwrite your CustomerData.toString() method.

Other than that you can extend slf4j but don't ask me how to do that.

Relevant