OPENDJ-308: Implement access log filtering and configurable message format

Matthew Swift

14.27.2011 2ba1652a6ce1a77eb0fcc86f678f4caab376720b

OPENDJ-308: Implement access log filtering and configurable message format

Add support for changing the format of the access log:

* configurable timestamp format
* enable logging of request and response control OIDS
* change the format to a "combined" mode where operations are logged using a single log record rather than individual request and response records.

Also fixed a bug in the time thread which prevented applications from deregistering time formatters.

 opends/resource/schema/02-config.ldif

@@ -2744,6 +2744,18 @@
  NAME 'ds-cfg-search-response-is-indexed'
  SYNTAX 1.3.6.1.4.1.1466.115.121.1.7
  X-ORIGIN 'OpenDJ Directory Server' )
attributeTypes: ( 1.3.6.1.4.1.36733.2.1.1.49
  NAME 'ds-cfg-log-format'
  SYNTAX 1.3.6.1.4.1.1466.115.121.1.15
  X-ORIGIN 'OpenDJ Directory Server' )
attributeTypes: ( 1.3.6.1.4.1.36733.2.1.1.50
  NAME 'ds-cfg-log-record-time-format'
  SYNTAX 1.3.6.1.4.1.1466.115.121.1.15
  X-ORIGIN 'OpenDJ Directory Server' )
attributeTypes: ( 1.3.6.1.4.1.36733.2.1.1.51
  NAME 'ds-cfg-log-control-oids'
  SYNTAX 1.3.6.1.4.1.1466.115.121.1.7
  X-ORIGIN 'OpenDJ Directory Server' )
objectClasses: ( 1.3.6.1.4.1.26027.1.2.1
  NAME 'ds-cfg-access-control-handler'
  SUP top
@@ -3009,7 +3021,10 @@
        ds-cfg-buffer-size $
        ds-cfg-auto-flush $
        ds-cfg-append $
        ds-cfg-queue-size )
        ds-cfg-queue-size $
        ds-cfg-log-format $
        ds-cfg-log-record-time-format $
        ds-cfg-log-control-oids )
  X-ORIGIN 'OpenDS Directory Server' )
objectClasses: ( 1.3.6.1.4.1.26027.1.2.26
  NAME 'ds-cfg-file-based-debug-log-publisher'

 opends/src/admin/defn/org/opends/server/admin/std/FileBasedAccessLogPublisherConfiguration.xml

@@ -286,4 +286,81 @@
      </ldap:attribute>
    </adm:profile>
  </adm:property>
  <adm:property name="log-format">
    <adm:synopsis>
      Specifies how log records should be formatted and written to the access log.
    </adm:synopsis>
    <adm:default-behavior>
      <adm:defined>
        <adm:value>multi-line</adm:value>
      </adm:defined>
    </adm:default-behavior>
    <adm:syntax>
      <adm:enumeration>
        <adm:value name="combined">
          <adm:synopsis>
            Combine log records for operation requests and responses into a
            single record. This format should be used when log records are to
            be filtered based on response criteria (e.g. result code).
          </adm:synopsis>
        </adm:value>
        <adm:value name="multi-line">
          <adm:synopsis>
            Outputs separate log records for operation requests and responses.
          </adm:synopsis>
        </adm:value>
      </adm:enumeration>
    </adm:syntax>
    <adm:profile name="ldap">
      <ldap:attribute>
        <ldap:name>ds-cfg-log-format</ldap:name>
      </ldap:attribute>
    </adm:profile>
  </adm:property>
  <adm:property name="log-record-time-format">
    <adm:synopsis>
      Specifies the format string that is used to generate log record
      timestamps.
    </adm:synopsis>
    <adm:default-behavior>
      <adm:defined>
        <adm:value>dd/MMM/yyyy:HH:mm:ss Z</adm:value>
      </adm:defined>
    </adm:default-behavior>
   <adm:syntax>
     <adm:string>
       <adm:pattern>
        <adm:regex>.*</adm:regex>
        <adm:usage>STRING</adm:usage>
          <adm:synopsis>
            Any valid format string that can be used with the 
            java.text.SimpleDateFormat class.
          </adm:synopsis>
        </adm:pattern>
      </adm:string>
    </adm:syntax>
    <adm:profile name="ldap">
      <ldap:attribute>
        <ldap:name>ds-cfg-log-record-time-format</ldap:name>
      </ldap:attribute>
    </adm:profile>
  </adm:property>
  <adm:property name="log-control-oids">
    <adm:synopsis>
      Specifies whether control OIDs will be included in operation log records.
    </adm:synopsis>
    <adm:default-behavior>
      <adm:defined>
        <adm:value>false</adm:value>
      </adm:defined>
    </adm:default-behavior>
    <adm:syntax>
      <adm:boolean />
    </adm:syntax>
    <adm:profile name="ldap">
      <ldap:attribute>
        <ldap:name>ds-cfg-log-control-oids</ldap:name>
      </ldap:attribute>
    </adm:profile>
  </adm:property>
</adm:managed-object>

 opends/src/admin/messages/FileBasedAccessLogPublisherCfgDefn.properties

@@ -12,10 +12,16 @@
property.filtering-policy.syntax.enumeration.value.inclusive.synopsis=Records must match at least one of the filtering criteria in order to be logged.
property.filtering-policy.syntax.enumeration.value.no-filtering.synopsis=No filtering will be performed, and all records will be logged.
property.java-class.synopsis=The fully-qualified name of the Java class that provides the File Based Access Log Publisher implementation.
property.log-control-oids.synopsis=Specifies whether control OIDs will be included in operation log records.
property.log-file.synopsis=The file name to use for the log files generated by the File Based Access Log Publisher. The path to the file is relative to the server root.
property.log-file.syntax.string.pattern.synopsis=A path to an existing file that is readable by the server.
property.log-file-permissions.synopsis=The UNIX permissions of the log files created by this File Based Access Log Publisher.
property.log-file-permissions.syntax.string.pattern.synopsis=A valid UNIX mode string. The mode string must contain three digits between zero and seven.
property.log-format.synopsis=Specifies how log records should be formatted and written to the access log.
property.log-format.syntax.enumeration.value.combined.synopsis=Combine log records for operation requests and responses into a single record. This format should be used when log records are to be filtered based on response criteria (e.g. result code).
property.log-format.syntax.enumeration.value.multi-line.synopsis=Outputs separate log records for operation requests and responses.
property.log-record-time-format.synopsis=Specifies the format string that is used to generate log record timestamps.
property.log-record-time-format.syntax.string.pattern.synopsis=Any valid format string that can be used with the java.text.SimpleDateFormat class.
property.queue-size.synopsis=The maximum number of log records that can be stored in the asynchronous queue.
property.queue-size.description=Setting the queue size to zero activates parallel log writer implementation which has no queue size limit and as such the parallel log writer should only be used on a very well tuned server configuration to avoid potential out of memory errors.
property.queue-size.requires-admin-action.synopsis=The File Based Access Log Publisher must be restarted if this property is changed and the asynchronous property is set to true.

 opends/src/messages/messages/config.properties

@@ -2169,3 +2169,6 @@
MILD_ERR_CONFIG_PWPOLICY_CANNOT_CHANGE_DEFAULT_POLICY_WRONG_TYPE_727=The \
 default password policy value '%s' is invalid because it refers to an \
 authentication policy which is not a password policy
SEVERE_ERR_CONFIG_LOGGING_INVALID_TIME_FORMAT_728=The timestamp format string \
 "%s" is not a valid format string.  The format string should conform to the \
 syntax described in the documentation for the "java.text.SimpleDateFormat" class

 opends/src/server/org/opends/server/loggers/TextAccessLogPublisher.java

@@ -35,6 +35,7 @@

import java.io.File;
import java.io.IOException;
import java.text.SimpleDateFormat;
import java.util.ArrayList;
import java.util.Iterator;
import java.util.LinkedHashSet;
@@ -43,6 +44,7 @@
import org.opends.messages.Message;
import org.opends.messages.MessageBuilder;
import org.opends.server.admin.server.ConfigurationChangeListener;
import org.opends.server.admin.std.meta.FileBasedAccessLogPublisherCfgDefn.*;
import org.opends.server.admin.std.server.FileBasedAccessLogPublisherCfg;
import org.opends.server.api.ClientConnection;
import org.opends.server.api.ExtendedOperationHandler;
@@ -100,6 +102,9 @@

  private TextWriter writer = null;
  private FileBasedAccessLogPublisherCfg cfg = null;
  private boolean isCombinedMode = false;
  private boolean includeControlOIDs = false;
  private String timeStampFormat = "dd/MMM/yyyy:HH:mm:ss Z";



@@ -207,7 +212,15 @@
          adminActionRequired = true;
        }

        if (!config.getLogRecordTimeFormat().equals(timeStampFormat))
        {
          TimeThread.removeUserDefinedFormatter(timeStampFormat);
          timeStampFormat = config.getLogRecordTimeFormat();
        }

        cfg = config;
        isCombinedMode = cfg.getLogFormat() == LogFormat.COMBINED;
        includeControlOIDs = cfg.isLogControlOids();
      }
    }
    catch (final Exception e)
@@ -228,21 +241,6 @@
   * {@inheritDoc}
   */
  @Override
  protected void close0()
  {
    writer.shutdown();
    if (cfg != null)
    {
      cfg.removeFileBasedAccessChangeListener(this);
    }
  }



  /**
   * {@inheritDoc}
   */
  @Override
  public void initializeAccessLogPublisher(
      final FileBasedAccessLogPublisherCfg cfg) throws ConfigException,
      InitializationException
@@ -311,7 +309,12 @@
    }

    initializeFilters(cfg);

    this.cfg = cfg;
    isCombinedMode = cfg.getLogFormat() == LogFormat.COMBINED;
    includeControlOIDs = cfg.isLogControlOids();
    timeStampFormat = cfg.getLogRecordTimeFormat();

    cfg.addFileBasedAccessChangeListener(this);
  }

@@ -337,6 +340,20 @@
      final FileBasedAccessLogPublisherCfg config,
      final List<Message> unacceptableReasons)
  {
    // Validate the time-stamp formatter.
    final String formatString = config.getLogRecordTimeFormat();
    try
    {
      new SimpleDateFormat(formatString);
    }
    catch (final Exception e)
    {
      final Message message = ERR_CONFIG_LOGGING_INVALID_TIME_FORMAT.get(String
          .valueOf(formatString));
      unacceptableReasons.add(message);
      return false;
    }

    // Make sure the permission is valid.
    try
    {
@@ -374,20 +391,14 @@
  @Override
  public void logAbandonRequest(final AbandonOperation abandonOperation)
  {
    if (!isRequestLoggable(abandonOperation))
    if (isCombinedMode || !isRequestLoggable(abandonOperation))
    {
      return;
    }

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(abandonOperation, "ABANDON", CATEGORY_REQUEST, buffer);
    buffer.append(" idToAbandon=");
    buffer.append(abandonOperation.getIDToAbandon());
    if (abandonOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }

    appendAbandonRequest(abandonOperation, buffer);
    writer.writeRecord(buffer.toString());
  }

@@ -411,6 +422,10 @@

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(abandonOperation, "ABANDON", CATEGORY_RESPONSE, buffer);
    if (isCombinedMode)
    {
      appendAbandonRequest(abandonOperation, buffer);
    }
    buffer.append(" result=");
    buffer.append(abandonOperation.getResultCode().getIntValue());
    final MessageBuilder msg = abandonOperation.getErrorMessage();
@@ -442,21 +457,14 @@
  @Override
  public void logAddRequest(final AddOperation addOperation)
  {
    if (!isRequestLoggable(addOperation))
    if (isCombinedMode || !isRequestLoggable(addOperation))
    {
      return;
    }

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(addOperation, "ADD", CATEGORY_REQUEST, buffer);
    buffer.append(" dn=\"");
    buffer.append(addOperation.getRawEntryDN().toString());
    buffer.append("\"");
    if (addOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }

    appendAddRequest(addOperation, buffer);
    writer.writeRecord(buffer.toString());
  }

@@ -480,6 +488,10 @@

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(addOperation, "ADD", CATEGORY_RESPONSE, buffer);
    if (isCombinedMode)
    {
      appendAddRequest(addOperation, buffer);
    }
    buffer.append(" result=");
    buffer.append(addOperation.getResultCode().getIntValue());

@@ -525,44 +537,14 @@
  @Override
  public void logBindRequest(final BindOperation bindOperation)
  {
    if (!isRequestLoggable(bindOperation))
    if (isCombinedMode || !isRequestLoggable(bindOperation))
    {
      return;
    }

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(bindOperation, "BIND", CATEGORY_REQUEST, buffer);

    final String protocolVersion = bindOperation.getProtocolVersion();
    if (protocolVersion != null)
    {
      buffer.append(" version=");
      buffer.append(protocolVersion);
    }

    switch (bindOperation.getAuthenticationType())
    {
    case SIMPLE:
      buffer.append(" type=SIMPLE");
      break;
    case SASL:
      buffer.append(" type=SASL mechanism=");
      buffer.append(bindOperation.getSASLMechanism());
      break;
    default:
      buffer.append(" type=");
      buffer.append(bindOperation.getAuthenticationType());
      break;
    }

    buffer.append(" dn=\"");
    buffer.append(bindOperation.getRawBindDN().toString());
    buffer.append("\"");
    if (bindOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }

    appendBindRequest(bindOperation, buffer);
    writer.writeRecord(buffer.toString());
  }

@@ -586,6 +568,10 @@

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(bindOperation, "BIND", CATEGORY_RESPONSE, buffer);
    if (isCombinedMode)
    {
      appendBindRequest(bindOperation, buffer);
    }
    buffer.append(" result=");
    buffer.append(bindOperation.getResultCode().getIntValue());

@@ -663,22 +649,14 @@
  @Override
  public void logCompareRequest(final CompareOperation compareOperation)
  {
    if (!isRequestLoggable(compareOperation))
    if (isCombinedMode || !isRequestLoggable(compareOperation))
    {
      return;
    }

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(compareOperation, "COMPARE", CATEGORY_REQUEST, buffer);
    buffer.append(" dn=\"");
    buffer.append(compareOperation.getRawEntryDN().toString());
    buffer.append("\" attr=");
    buffer.append(compareOperation.getAttributeType().getNameOrOID());
    if (compareOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }

    appendCompareRequest(compareOperation, buffer);
    writer.writeRecord(buffer.toString());
  }

@@ -702,6 +680,10 @@

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(compareOperation, "COMPARE", CATEGORY_RESPONSE, buffer);
    if (isCombinedMode)
    {
      appendCompareRequest(compareOperation, buffer);
    }
    buffer.append(" result=");
    buffer.append(compareOperation.getResultCode().getIntValue());

@@ -783,21 +765,14 @@
  @Override
  public void logDeleteRequest(final DeleteOperation deleteOperation)
  {
    if (!isRequestLoggable(deleteOperation))
    if (isCombinedMode || !isRequestLoggable(deleteOperation))
    {
      return;
    }

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(deleteOperation, "DELETE", CATEGORY_REQUEST, buffer);
    buffer.append(" dn=\"");
    buffer.append(deleteOperation.getRawEntryDN().toString());
    buffer.append("\"");
    if (deleteOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }

    appendDeleteRequest(deleteOperation, buffer);
    writer.writeRecord(buffer.toString());
  }

@@ -821,6 +796,10 @@

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(deleteOperation, "DELETE", CATEGORY_RESPONSE, buffer);
    if (isCombinedMode)
    {
      appendDeleteRequest(deleteOperation, buffer);
    }
    buffer.append(" result=");
    buffer.append(deleteOperation.getResultCode().getIntValue());

@@ -910,35 +889,14 @@
  @Override
  public void logExtendedRequest(final ExtendedOperation extendedOperation)
  {
    if (!isRequestLoggable(extendedOperation))
    if (isCombinedMode || !isRequestLoggable(extendedOperation))
    {
      return;
    }

    String name = null;
    final String oid = extendedOperation.getRequestOID();
    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(extendedOperation, "EXTENDED", CATEGORY_REQUEST, buffer);
    final ExtendedOperationHandler<?> extOpHandler = DirectoryServer
        .getExtendedOperationHandler(oid);
    if (extOpHandler != null)
    {
      name = extOpHandler.getExtendedOperationName();
      if (name != null)
      {
        buffer.append(" name=\"");
        buffer.append(name);
        buffer.append("\"");
      }
    }
    buffer.append(" oid=\"");
    buffer.append(oid);
    buffer.append("\"");
    if (extendedOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }

    appendExtendedRequest(extendedOperation, buffer);
    writer.writeRecord(buffer.toString());
  }

@@ -962,6 +920,10 @@

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(extendedOperation, "EXTENDED", CATEGORY_RESPONSE, buffer);
    if (isCombinedMode)
    {
      appendExtendedRequest(extendedOperation, buffer);
    }

    String name = null;
    final String oid = extendedOperation.getResponseOID();
@@ -1021,31 +983,14 @@
  @Override
  public void logModifyDNRequest(final ModifyDNOperation modifyDNOperation)
  {
    if (!isRequestLoggable(modifyDNOperation))
    if (isCombinedMode || !isRequestLoggable(modifyDNOperation))
    {
      return;
    }

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(modifyDNOperation, "MODIFYDN", CATEGORY_REQUEST, buffer);
    buffer.append(" dn=\"");
    buffer.append(modifyDNOperation.getRawEntryDN().toString());
    buffer.append("\" newRDN=\"");
    buffer.append(modifyDNOperation.getRawNewRDN().toString());
    buffer.append("\" deleteOldRDN=");
    buffer.append(modifyDNOperation.deleteOldRDN());

    final ByteString newSuperior = modifyDNOperation.getRawNewSuperior();
    if (newSuperior != null)
    {
      buffer.append(" newSuperior=\"");
      buffer.append(newSuperior.toString());
    }
    if (modifyDNOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }

    appendModifyDNRequest(modifyDNOperation, buffer);
    writer.writeRecord(buffer.toString());
  }

@@ -1069,6 +1014,10 @@

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(modifyDNOperation, "MODIFYDN", CATEGORY_RESPONSE, buffer);
    if (isCombinedMode)
    {
      appendModifyDNRequest(modifyDNOperation, buffer);
    }
    buffer.append(" result=");
    buffer.append(modifyDNOperation.getResultCode().getIntValue());

@@ -1114,21 +1063,14 @@
  @Override
  public void logModifyRequest(final ModifyOperation modifyOperation)
  {
    if (!isRequestLoggable(modifyOperation))
    if (isCombinedMode || !isRequestLoggable(modifyOperation))
    {
      return;
    }

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(modifyOperation, "MODIFY", CATEGORY_REQUEST, buffer);
    buffer.append(" dn=\"");
    buffer.append(modifyOperation.getRawEntryDN().toString());
    buffer.append("\"");
    if (modifyOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }

    appendModifyRequest(modifyOperation, buffer);
    writer.writeRecord(buffer.toString());
  }

@@ -1152,6 +1094,10 @@

    final StringBuilder buffer = new StringBuilder(100);
    appendHeader(modifyOperation, "MODIFY", CATEGORY_RESPONSE, buffer);
    if (isCombinedMode)
    {
      appendModifyRequest(modifyOperation, buffer);
    }
    buffer.append(" result=");
    buffer.append(modifyOperation.getResultCode().getIntValue());

@@ -1197,44 +1143,14 @@
  @Override
  public void logSearchRequest(final SearchOperation searchOperation)
  {
    if (!isRequestLoggable(searchOperation))
    if (isCombinedMode || !isRequestLoggable(searchOperation))
    {
      return;
    }

    final StringBuilder buffer = new StringBuilder(192);
    appendHeader(searchOperation, "SEARCH", CATEGORY_REQUEST, buffer);
    buffer.append(" base=\"");
    buffer.append(searchOperation.getRawBaseDN().toString());
    buffer.append("\" scope=");
    buffer.append(searchOperation.getScope());
    buffer.append(" filter=\"");
    searchOperation.getRawFilter().toString(buffer);

    final LinkedHashSet<String> attrs = searchOperation.getAttributes();
    if ((attrs == null) || attrs.isEmpty())
    {
      buffer.append("\" attrs=\"ALL\"");
    }
    else
    {
      buffer.append("\" attrs=\"");

      final Iterator<String> iterator = attrs.iterator();
      buffer.append(iterator.next());
      while (iterator.hasNext())
      {
        buffer.append(",");
        buffer.append(iterator.next());
      }

      buffer.append("\"");
    }
    if (searchOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }

    appendSearchRequest(searchOperation, buffer);
    writer.writeRecord(buffer.toString());
  }

@@ -1258,6 +1174,10 @@

    final StringBuilder buffer = new StringBuilder(128);
    appendHeader(searchOperation, "SEARCH", CATEGORY_RESPONSE, buffer);
    if (isCombinedMode)
    {
      appendSearchRequest(searchOperation, buffer);
    }
    buffer.append(" result=");
    buffer.append(searchOperation.getResultCode().getIntValue());

@@ -1306,7 +1226,6 @@
  @Override
  public void logUnbind(final UnbindOperation unbindOperation)
  {
    // FIXME: ensure that these are logged in combined mode.
    if (!isRequestLoggable(unbindOperation))
    {
      return;
@@ -1324,16 +1243,160 @@



  /**
   * {@inheritDoc}
   */
  @Override
  protected void close0()
  {
    writer.shutdown();
    TimeThread.removeUserDefinedFormatter(timeStampFormat);
    if (cfg != null)
    {
      cfg.removeFileBasedAccessChangeListener(this);
    }
  }



  private void appendAbandonRequest(final AbandonOperation abandonOperation,
      final StringBuilder buffer)
  {
    buffer.append(" idToAbandon=");
    buffer.append(abandonOperation.getIDToAbandon());
    appendRequestControls(abandonOperation, buffer);
    if (abandonOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }
  }



  private void appendAddRequest(final AddOperation addOperation,
      final StringBuilder buffer)
  {
    buffer.append(" dn=\"");
    buffer.append(addOperation.getRawEntryDN().toString());
    buffer.append("\"");
    appendRequestControls(addOperation, buffer);
    if (addOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }
  }



  private void appendBindRequest(final BindOperation bindOperation,
      final StringBuilder buffer)
  {
    final String protocolVersion = bindOperation.getProtocolVersion();
    if (protocolVersion != null)
    {
      buffer.append(" version=");
      buffer.append(protocolVersion);
    }

    switch (bindOperation.getAuthenticationType())
    {
    case SIMPLE:
      buffer.append(" type=SIMPLE");
      break;
    case SASL:
      buffer.append(" type=SASL mechanism=");
      buffer.append(bindOperation.getSASLMechanism());
      break;
    default:
      buffer.append(" type=");
      buffer.append(bindOperation.getAuthenticationType());
      break;
    }

    buffer.append(" dn=\"");
    buffer.append(bindOperation.getRawBindDN().toString());
    buffer.append("\"");
    appendRequestControls(bindOperation, buffer);
    if (bindOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }
  }



  private void appendCompareRequest(final CompareOperation compareOperation,
      final StringBuilder buffer)
  {
    buffer.append(" dn=\"");
    buffer.append(compareOperation.getRawEntryDN().toString());
    buffer.append("\" attr=");
    buffer.append(compareOperation.getAttributeType().getNameOrOID());
    appendRequestControls(compareOperation, buffer);
    if (compareOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }
  }



  private void appendDeleteRequest(final DeleteOperation deleteOperation,
      final StringBuilder buffer)
  {
    buffer.append(" dn=\"");
    buffer.append(deleteOperation.getRawEntryDN().toString());
    buffer.append("\"");
    appendRequestControls(deleteOperation, buffer);
    if (deleteOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }
  }



  private void appendExtendedRequest(final ExtendedOperation extendedOperation,
      final StringBuilder buffer)
  {
    final String oid = extendedOperation.getRequestOID();
    final ExtendedOperationHandler<?> extOpHandler = DirectoryServer
        .getExtendedOperationHandler(oid);
    if (extOpHandler != null)
    {
      final String name = extOpHandler.getExtendedOperationName();
      if (name != null)
      {
        buffer.append(" name=\"");
        buffer.append(name);
        buffer.append("\"");
      }
    }
    buffer.append(" oid=\"");
    buffer.append(oid);
    buffer.append("\"");
    appendRequestControls(extendedOperation, buffer);
    if (extendedOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }
  }



  // Appends the common log header information to the provided buffer.
  private void appendHeader(final Operation operation, final String opType,
      final String category, final StringBuilder buffer)
  {
    buffer.append('[');
    buffer.append(TimeThread.getLocalTime());
    buffer.append(TimeThread.getUserDefinedTime(timeStampFormat));
    buffer.append("] ");
    buffer.append(opType);
    buffer.append(' ');
    buffer.append(category);
    if (!isCombinedMode)
    {
      buffer.append(' ');
      buffer.append(category);
    }
    buffer.append(" conn=");
    buffer.append(operation.getConnectionID());
    buffer.append(" op=");
@@ -1344,10 +1407,131 @@



  private void appendModifyDNRequest(final ModifyDNOperation modifyDNOperation,
      final StringBuilder buffer)
  {
    buffer.append(" dn=\"");
    buffer.append(modifyDNOperation.getRawEntryDN().toString());
    buffer.append("\" newRDN=\"");
    buffer.append(modifyDNOperation.getRawNewRDN().toString());
    buffer.append("\" deleteOldRDN=");
    buffer.append(modifyDNOperation.deleteOldRDN());

    final ByteString newSuperior = modifyDNOperation.getRawNewSuperior();
    if (newSuperior != null)
    {
      buffer.append(" newSuperior=\"");
      buffer.append(newSuperior.toString());
    }
    appendRequestControls(modifyDNOperation, buffer);
    if (modifyDNOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }
  }



  private void appendModifyRequest(final ModifyOperation modifyOperation,
      final StringBuilder buffer)
  {
    buffer.append(" dn=\"");
    buffer.append(modifyOperation.getRawEntryDN().toString());
    buffer.append("\"");
    appendRequestControls(modifyOperation, buffer);
    if (modifyOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }
  }



  private void appendRequestControls(final Operation operation,
      final StringBuilder buffer)
  {
    if (includeControlOIDs && !operation.getRequestControls().isEmpty())
    {
      buffer.append(" requestControls=");
      boolean isFirst = true;
      for (final Control control : operation.getRequestControls())
      {
        if (!isFirst)
        {
          buffer.append(",");
        }
        buffer.append(control.getOID());
        isFirst = false;
      }
    }
  }



  private void appendResponseControls(final Operation operation,
      final StringBuilder buffer)
  {
    if (includeControlOIDs && !operation.getResponseControls().isEmpty())
    {
      buffer.append(" responseControls=");
      boolean isFirst = true;
      for (final Control control : operation.getResponseControls())
      {
        if (!isFirst)
        {
          buffer.append(",");
        }
        buffer.append(control.getOID());
        isFirst = false;
      }
    }
  }



  private void appendSearchRequest(final SearchOperation searchOperation,
      final StringBuilder buffer)
  {
    buffer.append(" base=\"");
    buffer.append(searchOperation.getRawBaseDN().toString());
    buffer.append("\" scope=");
    buffer.append(searchOperation.getScope());
    buffer.append(" filter=\"");
    searchOperation.getRawFilter().toString(buffer);

    final LinkedHashSet<String> attrs = searchOperation.getAttributes();
    if ((attrs == null) || attrs.isEmpty())
    {
      buffer.append("\" attrs=\"ALL\"");
    }
    else
    {
      buffer.append("\" attrs=\"");

      final Iterator<String> iterator = attrs.iterator();
      buffer.append(iterator.next());
      while (iterator.hasNext())
      {
        buffer.append(",");
        buffer.append(iterator.next());
      }

      buffer.append("\"");
    }
    appendRequestControls(searchOperation, buffer);
    if (searchOperation.isSynchronizationOperation())
    {
      buffer.append(" type=synchronization");
    }
  }



  // Appends additional log items to the provided builder.
  private void logAdditionalLogItems(final Operation operation,
      final StringBuilder builder)
  {
    appendResponseControls(operation, builder);
    for (final AdditionalLogItem item : operation.getAdditionalLogItems())
    {
      builder.append(' ');

 opends/src/server/org/opends/server/util/TimeThread.java

@@ -23,6 +23,7 @@
 *
 *
 *      Copyright 2006-2009 Sun Microsystems, Inc.
 *      Portions copyright 2011 ForgeRock AS.
 */
package org.opends.server.util;

@@ -34,7 +35,6 @@
import java.util.Calendar;
import java.util.Date;
import java.util.GregorianCalendar;
import java.util.Iterator;
import java.util.List;
import java.util.Map;
import java.util.TimeZone;
@@ -392,17 +392,8 @@
  {
    checkState();

    Iterator<SimpleDateFormat> iterator =
        INSTANCE.timeInfo.userDefinedFormatters.iterator();
    while (iterator.hasNext())
    {
      SimpleDateFormat format = iterator.next();
      if (format.toPattern().equals(formatString))
      {
        iterator.remove();
      }
    }

    INSTANCE.timeInfo.userDefinedFormatters.remove(new SimpleDateFormat(
        formatString));
    INSTANCE.timeInfo.userDefinedTimeStrings.remove(formatString);
  }