Conditional logging with log4j

问题:

The web application on which I am working occasionally develops data integrity issues for some of the users. I'd like to turn on trace level logging, but since we are dealing with 100s of requests per second trace logging every single request is out of the question.

Is there a way with log4j to be able to log conditionally? In other words, I would like to be able to get trace logs only when specific users make a request. Since I don't know beforehand which users will be affected, I cannot simply temporarily hard-code usernames.

Edit:

I think I need to be a little clearer. I can easily add conditions to my log statements. For example

Logger logger = Logger.getLogger("foo");
String usernameFilter = "piglet";
String username = request.getParameter("username");
logger.setLevel(usernameFilter.equals(username) ? Level.TRACE : Level.INFO);
if (logger.isTraceEnabled()) {
   logger.trace("blah blah blah");
}

The difficulty is dynamically altering the condition that sets the log level. In other words, in the example above, how can I set the value of usernameFilter, other than hard-coding it.

回答1:

You want to look at Nested Diagnostic Contexts or Mapped Diagnostic Contexts in log4j or slf4j. An NDC/MDC allows you to insert data into your session that can be filtered by log4j.

So you would define the user name to be in the NDC and then you can change the log4j.properties to change the logging level for specific users.

An MDC uses a Map, whereas an NDC is based upon a stack principle. If you're using slf4j, you can even create separate log files depending upon the information in your MDC.

For instance, we did this when users logged into a website. We wanted to trace what a particular user was doing (retrospectively), so we added the user name and session id to the NDC, and then we could post filter on those.

The code was similar to the following:

public class LoggingFilter implements Filter {
    @Override
    public void doFilter(ServletRequest request, ServletResponse response,
            FilterChain chain) throws IOException, ServletException {
        MDC.put("username", session.getParameter("username")); // or where ever t is stored
        chain.doFilter(request, response);
    }
}

In your log4j.xml, this filters based upon the user:

  <appender name="UserDebug" class="org.apache.log4j.RollingFileAppender">
    <param name="File" value="userdebug.log"/>
    <param name="Append" value="true"/>
    <param name="MaxFileSize" value="5000KB"/>
    <param name="maxBackupIndex" value="5"/> 
          <layout class="org.apache.log4j.PatternLayout">
                  <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss} [%t] user:%X{username} %-5p - %m%n" />
          </layout>

          <filter class="org.apache.log4j.varia.StringMatchFilter">
                  <param name="StringToMatch" value="user:fred" />
                  <param name="AcceptOnMatch" value="true" />
          </filter>

      <filter class="org.apache.log4j.varia.DenyAllFilter"/>
  </appender>

%X{key} outputs the value of MDC.get(key) in an MDC. If you wanted a more complex filter, you can extend it yourself, and look at the values in the MDC yourself.

回答2:

Matthew Farwell's answer (use MDC) is the one that worked for me and he mentions writing your own filter. My need was to hide logging messages in certain cases. Specifically, we have a health check call that is hit much more frequently than typical user usage and it was filling the logs unnecessarily. Matthew's solution doesn't fit my situation because it requires you to add the MDC to the actual log output. I only want to use the MDC for filtering, so I extended org.apache.log4j.spi.Filter with the following class:

/**
 * Log4J filter that stops certain log messages from being logged, based on a
 * value in the MDC (See Log4J docs).
 */
public class Log4JMDCFilter extends Filter
{

private String keyToMatch;
private String valueToMatch;
private boolean denyOnMatch = true;

/**
 * {@inheritDoc}
 */
public int decide(LoggingEvent event)
{
    if (keyToMatch != null && valueToMatch != null
        && valueToMatch.equals(event.getMDC(keyToMatch)))
    {
        return denyOnMatch ? DENY : ACCEPT;
    }

    return denyOnMatch ? ACCEPT : DENY;
}

/**
 * The key on which to filter.
 * 
 * @return key on which to filter
 */
public String getKeyToMatch()
{
    return keyToMatch;
}

/**
 * Sets the key on which to filter.
 * 
 * @param keyToMatch key on which to filter
 */
public void setKeyToMatch(String keyToMatch)
{
    this.keyToMatch = keyToMatch;
}

/**
 * Gets the value to match.
 * 
 * @return the value to match.
 */
public String getValueToMatch()
{
    return valueToMatch;
}

/**
 * Sets the value to match.
 * 
 * @param valueToMatch the value to match.
 */
public void setValueToMatch(String valueToMatch)
{
    this.valueToMatch = valueToMatch;
}

/**
 * Returns true if the log message should not be logged if a match is found.
 * 
 * @return true if the log message should not be logged if a match is found.
 */
public boolean isDenyOnMatch()
{
    return denyOnMatch;
}

/**
 * Set this to "true" if you do not want log messages that match the given
 * key/value to be logged. False if you only want messages that match to be
 * logged.
 * 
 * @param denyOnMatch "true" if you do not want log messages that match the
 *        given key/value to be logged. False if you only want messages that
 *        match to be logged.
 */
public void setDenyOnMatch(String denyOnMatch)
{
    this.denyOnMatch = Boolean.valueOf(denyOnMatch).booleanValue();
}

}

Use the following log4j.xml snippet to activate the filter ("HEALTHCHECK" is the key and "true" is the value I'm filtering on):

    <filter class="com.copart.hh.core.utils.Log4JMDCFilter">
        <param name="keyToMatch" value="HEALTHCHECK" />
        <param name="valueToMatch" value="true" />
        <param name="denyOnMatch" value="true" />
    </filter>

Then, anywhere you want to mark for filtering, put in code like this:

MDC.put("HEALTHCHECK", "true");
try
{    
      // do healthcheck stuff that generates unnecessary logs
}
finally
{
    MDC.remove("HEALTHCHECK"); // not sure this is strictly necessary
}

回答3:

I found this blog article very helpful. This may help you with creating conditions to log for your users.

回答4:

I make a workaround as follow

Config your log target in log4j.xml like the following:

    <appender name="file" class="org.apache.log4j.RollingFileAppender">
    <param name="file" value="${catalina.home}/logs/uploader.log" />
    <param name="append" value="false" />
    <param name="threshold" value="info" />
    <layout class="org.apache.log4j.PatternLayout">
        <param name="ConversionPattern" value="%d{ISO8601} %-5p [%c{1}] - %m%n" />
    </layout>

    <filter class="org.apache.log4j.varia.StringMatchFilter">
        <param name="StringToMatch" value="trackfile" />
        <param name="AcceptOnMatch" value="true" />
    </filter>

     <filter class="org.apache.log4j.varia.DenyAllFilter" />   
</appender>

create a customer logger method that append your target tag [trackfile]

private void logfile(String msg) {
    logger.info("trackfile: " + msg);
}

log your information using the above method:

logfile("your log message")