OPENDJ-2006 Add Jul to Slf4j bridge

Gaetan Boismal

09.27.2015 efc41e456f715abe57a69d6136a2d1a1098eae4c

OPENDJ-2006 Add Jul to Slf4j bridge

This commit adds support of the java.util.logging (Jul) to slf4j bridge.
Integration overview:
The jul-to-slf4j bridge has been added as a maven dependency. It simply
declares an Handler at the root level which redirect logs to slf4j.
Note that we still have to configure the Jul log level to avoid major
performance issue described here: http://www.slf4j.org/legacy.html#jul-
to-slf4.
Binding between Jul and slf4j log levels are described here:
http://www.slf4j.org/api/org/slf4j/bridge/SLF4JBridgeHandler.html
Binding between our loggers and Jul is done as follow:

* If there at least one Debug log publisher enabled then Jul level is
configured as FINEST.
* Else we compute the lowest level of all enabled error log publishers
and we apply the following binding between error log publisher default
severity and Jul Level:
    * DEBUG, INFORMATION, NOTICE -> Jul INFO
    * WARNING -> Jul WARNING
    * ERROR -> Jul SEVERE

Integration details:
The bridge is managed in the LoggerConfigManager.JulToSlf4jLogManager
inner class.
We compute the Jul log level when the following events occured:

* Add or remove a debug/error log publisher
* Error log publisher configuration change.

 opendj-server-legacy/pom.xml

@@ -119,11 +119,6 @@
    </dependency>

    <dependency>
      <groupId>org.slf4j</groupId>
      <artifactId>slf4j-jdk14</artifactId>
    </dependency>

    <dependency>
      <groupId>org.forgerock.commons</groupId>
      <artifactId>forgerock-util</artifactId>
    </dependency>
@@ -174,6 +169,17 @@
      <artifactId>forgerock-audit-handler-jdbc</artifactId>
    </dependency>

    <!-- slf4j libraries -->
    <dependency>
      <groupId>org.slf4j</groupId>
      <artifactId>slf4j-jdk14</artifactId>
    </dependency>

    <dependency>
      <groupId>org.slf4j</groupId>
      <artifactId>jul-to-slf4j</artifactId>
    </dependency>

    <!-- servlet and mail -->
    <dependency>
      <groupId>javax.servlet</groupId>
@@ -549,6 +555,9 @@
              <classPathProperty>classpath.bootstrap-client</classPathProperty>
              <productJarName>${product.name.lowercase}</productJarName>
              <supportedLocales>${locales}</supportedLocales>
              <excludes>
                <exclude>org.slf4j:jul-to-slf4j</exclude>
              </excludes>
              <additionalJars>
                 <additionalJar>opendj-je-backend.jar</additionalJar>
              </additionalJars>

 opendj-server-legacy/src/main/java/org/opends/server/core/DirectoryServer.java

@@ -764,6 +764,12 @@
    {
      return directoryServer.commonAudit;
    }

    @Override
    public LoggerConfigManager getLoggerConfigManager()
    {
      return directoryServer.loggerConfigManager;
    }
  }

  /**

 opendj-server-legacy/src/main/java/org/opends/server/core/LoggerConfigManager.java

@@ -28,13 +28,18 @@

import static org.opends.messages.ConfigMessages.*;

import java.io.ByteArrayInputStream;
import java.io.IOException;
import java.util.ArrayList;
import java.util.List;
import java.util.logging.Level;
import java.util.logging.LogManager;

import org.forgerock.i18n.LocalizableMessage;
import org.forgerock.i18n.slf4j.LocalizedLogger;
import org.forgerock.opendj.config.server.ConfigException;
import org.forgerock.opendj.ldap.ResultCode;
import org.opends.messages.Severity;
import org.opends.server.admin.server.ConfigurationAddListener;
import org.opends.server.admin.server.ConfigurationDeleteListener;
import org.opends.server.admin.server.ServerManagementContext;
@@ -51,6 +56,7 @@
import org.opends.server.loggers.HTTPAccessLogger;
import org.forgerock.opendj.config.server.ConfigChangeResult;
import org.opends.server.types.InitializationException;
import org.slf4j.bridge.SLF4JBridgeHandler;

/**
 * This class defines a utility that will be used to manage the set of loggers
@@ -64,8 +70,96 @@

  private static final LocalizedLogger logger = LocalizedLogger.getLoggerForThisClass();

  /**
   * Class to manage java.util.logging to slf4j bridge.
   * Main purpose of this class is to adapt the j.u.l log level when a debug/error log publisher change is detected.
   * <p>
   * @ThreadSafe
   */
  private static class JulToSlf4jLogManager
  {
    private Level currentJulLogLevel = Level.OFF;
    private final Object lock = new Object();

    private Level computeJulLogLevel()
    {
      if (DebugLogger.getInstance().isEnabled())
      {
        return Level.FINEST;
      }

      for (final Severity severity : Severity.values())
      {
        if (ErrorLogger.isEnabledFor("", severity))
        {
          return errorLoggerSeverityToJulLevel(severity);
        }
      }
      return Level.OFF;
    }

    private void adjustJulLevel()
    {
      final Level newLevel1 = computeJulLogLevel();
      if (isMoreDetailedThanCurrentLevel(newLevel1))
      {
        synchronized (lock)
        {
          final Level newLevel2 = computeJulLogLevel();
          if (isMoreDetailedThanCurrentLevel(newLevel2))
          {
            changeJulLogLevel(newLevel2);
          }
        }
      }
    }

    private void changeJulLogLevel(final Level newLevel)
    {
      try
      {
        SLF4JBridgeHandler.removeHandlersForRootLogger();
        // This is needed to avoid major performance issue. See: http://www.slf4j.org/legacy.html#jul-to-slf4j
        LogManager.getLogManager().readConfiguration(
                new ByteArrayInputStream((".level=" + newLevel).getBytes()));
        SLF4JBridgeHandler.install();
        currentJulLogLevel = newLevel;
      }
      catch (IOException | SecurityException e)
      {
        logger.error(ERR_CONFIG_CANNOT_CONFIGURE_JUL_LOGGER.get(e.getMessage()), e);
        SLF4JBridgeHandler.removeHandlersForRootLogger();
      }
    }

    private boolean isMoreDetailedThanCurrentLevel(final Level challenger)
    {
      return challenger.intValue() < currentJulLogLevel.intValue();
    }

    /** Convert OpenDJ error log severity to JUL Severity. */
    private Level errorLoggerSeverityToJulLevel(Severity severity)
    {
      switch (severity)
      {
      case DEBUG:
      case INFORMATION:
      case NOTICE:
        return Level.INFO;
      case WARNING:
        return Level.WARNING;
      case ERROR:
        return Level.SEVERE;
      default:
        return Level.OFF;
      }
    }
  }

  private final ServerContext serverContext;

  private final JulToSlf4jLogManager julToSlf4jManager = new JulToSlf4jLogManager();

  /**
   * Create the logger config manager with the provided
   * server context.
@@ -147,6 +241,7 @@
    AccessLogger.getInstance().initializeLogger(accessPublisherCfgs, serverContext);
    HTTPAccessLogger.getInstance().initializeLogger(httpAccessPublisherCfgs, serverContext);
    ErrorLogger.getInstance().initializeLogger(errorPublisherCfgs, serverContext);
    julToSlf4jManager.adjustJulLevel();
  }

  /**
@@ -227,4 +322,13 @@
    ccr.setResultCode(ResultCode.UNWILLING_TO_PERFORM);
    return ccr;
  }

  /**
   * Update the current java.util.logging.Level.
   * This level is used to filter logs from third party libraries which use j.u.l to our slf4j logger.
   */
  public void adjustJulLevel()
  {
    julToSlf4jManager.adjustJulLevel();
  }
}

 opendj-server-legacy/src/main/java/org/opends/server/core/ServerContext.java

@@ -106,4 +106,11 @@
   * @return the common audit manager
   */
  CommonAudit getCommonAudit();

  /**
   * Returns the logger config manager.
   *
   * @return the logger config manager
   */
  LoggerConfigManager getLoggerConfigManager();
}

 opendj-server-legacy/src/main/java/org/opends/server/loggers/DebugLogger.java

@@ -38,6 +38,7 @@
import org.opends.server.admin.ClassPropertyDefinition;
import org.opends.server.admin.std.meta.DebugLogPublisherCfgDefn;
import org.opends.server.admin.std.server.DebugLogPublisherCfg;
import org.opends.server.core.ServerContext;

/**
 * A logger for debug and trace logging. DebugLogger provides a debugging
@@ -197,6 +198,7 @@
    loggerStorage.addLogPublisher(publisher);
    updateTracerSettings();
    enabled = true;
    adjustJulLevel();
  }

  @Override
@@ -205,6 +207,7 @@
    boolean removed = loggerStorage.removeLogPublisher(publisher);
    updateTracerSettings();
    enabled = !loggerStorage.getLogPublishers().isEmpty();
    adjustJulLevel();
    return removed;
  }

@@ -214,6 +217,24 @@
    loggerStorage.removeAllLogPublishers();
    updateTracerSettings();
    enabled = false;
    adjustJulLevel();
  }

  private void adjustJulLevel()
  {
    final ServerContext serverContext = getServerContext();
    if (serverContext != null)
    {
      serverContext.getLoggerConfigManager().adjustJulLevel();
    }
  }

  /**
   * Returns whether there is at least one debug log publisher enabled.
   * @return whether there is at least one debug log publisher enabled.
   */
  public boolean isEnabled()
  {
    return enabled;
  }
}

 opendj-server-legacy/src/main/java/org/opends/server/loggers/ErrorLogger.java

@@ -37,6 +37,7 @@
import org.opends.server.admin.std.server.ErrorLogPublisherCfg;
import org.opends.server.api.DirectoryThread;
import org.opends.server.backends.task.Task;
import org.opends.server.core.ServerContext;

/**
 * This class defines the wrapper that will invoke all registered error loggers
@@ -161,17 +162,30 @@
  public final synchronized void addLogPublisher(final ErrorLogPublisher<ErrorLogPublisherCfg> publisher)
  {
    loggerStorage.addLogPublisher(publisher);
    adjustJulLevel();
  }

  @Override
  public final synchronized boolean removeLogPublisher(final ErrorLogPublisher<ErrorLogPublisherCfg> publisher)
  {
    return loggerStorage.removeLogPublisher(publisher);
    final boolean removed = loggerStorage.removeLogPublisher(publisher);
    adjustJulLevel();
    return removed;
  }

  @Override
  public final synchronized void removeAllLogPublishers()
  {
    loggerStorage.removeAllLogPublishers();
    adjustJulLevel();
  }

  private void adjustJulLevel()
  {
    final ServerContext serverContext = getServerContext();
    if (serverContext != null)
    {
      serverContext.getLoggerConfigManager().adjustJulLevel();
    }
  }
}

 opendj-server-legacy/src/main/java/org/opends/server/loggers/TextErrorLogPublisher.java

@@ -62,6 +62,7 @@
{
  private TextWriter writer;
  private FileBasedErrorLogPublisherCfg currentConfig;
  private ServerContext serverContext;

  /**
   * Returns a new text error log publisher which will print all messages to the
@@ -105,6 +106,7 @@
  public void initializeLogPublisher(FileBasedErrorLogPublisherCfg config, ServerContext serverContext)
      throws ConfigException, InitializationException
  {
    this.serverContext = serverContext;
    File logFile = getLogFile(config);
    FileNamingPolicy fnPolicy = new TimeStampNaming(logFile);

@@ -350,6 +352,7 @@

        currentConfig = config;
      }
      serverContext.getLoggerConfigManager().adjustJulLevel();
    }
    catch(Exception e)
    {

 opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HTTPConnectionHandler.java

@@ -52,8 +52,6 @@
import java.util.TreeSet;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.TimeUnit;
import java.util.logging.Level;
import java.util.logging.Logger;

import org.forgerock.http.servlet.HttpFrameworkServlet;
import org.forgerock.i18n.LocalizableMessage;
@@ -707,9 +705,6 @@

  private void startHttpServer() throws Exception
  {
    // Silence Grizzly's own logging
    Logger.getLogger("org.glassfish.grizzly").setLevel(Level.OFF);

    if (HTTPAccessLogger.getHTTPAccessLogPublishers().isEmpty())
    {
      logger.warn(WARN_CONFIG_LOGGER_NO_ACTIVE_HTTP_ACCESS_LOGGERS);

 opendj-server-legacy/src/messages/org/opends/messages/config.properties

@@ -947,4 +947,6 @@
 configuration entry %s: %s
ERR_CONFIG_LOGGER_CANNOT_DELETE_LOGGER_736=An error occurred while \
 attempting to delete a Directory Server logger from the information in \
 configuration entry %s: %s
 configuration entry %s: %s
ERR_CONFIG_CANNOT_CONFIGURE_JUL_LOGGER_737=Cannot configure \
 java.util.logging root logger level: %s. java.util.logging support is now disabled.

 opendj-server-legacy/src/messages/src/org/opends/messages/Severity.java

@@ -46,31 +46,21 @@
    mayInvoke=true)
public enum Severity {

  /**
   * The severity that will be used for informational messages.
   */
  INFORMATION("INFO"),

  /**
   * The severity that will be used for warning messages.
   */
  WARNING("WARN"),

  /**
   * The severity that will be used for warning messages.
   */
  ERROR("ERR"),

  /**
   * The severity that will be used for debug messages.
   */
  /** The severity that will be used for debug messages. */
  DEBUG("DEBUG"),

  /**
   * The severity that will be used for important informational
   * messages.
   */
  NOTICE("NOTE");
  /** The severity that will be used for informational messages. */
  INFORMATION("INFO"),

  /** The severity that will be used for important informational messages. */
  NOTICE("NOTE"),

  /** The severity that will be used for warning messages. */
  WARNING("WARN"),

  /** The severity that will be used for warning messages. */
  ERROR("ERR");


  private static Set<String> PROPERTY_KEY_FORM_VALUES_SET;