Fix for issue 1321 : Synchronization changes aren't logged by default

gbellato

11.14.2007 b80ead961b3e5e12f9f2e9e001a247c17041beb0

Fix for issue 1321 : Synchronization changes aren't logged by default

This adds a  new configuration property for the accessLogPublishers :  ds-cfg-suppress-synchronization-operations.
It can be used to configure the behaviour of some log publisher with regards to the synchronization operations.

When set to false (which is the default value) the access log publisher will log the synchronization operation.
When set to true, the access log publisher will not log the synchronization operation.
The property ds-cfg-suppress-internal-operations that control the logging of the internal operations
now does not have any effect on the synchronization operation (so that one can configure the
server to log all internal operations except the synchronization ones)

Both the access log and the audit log implement this property.

I've also added the string : "type=synchronization" at the end of the line corresponding
to the operation request in the access log so that it is possible to
differentiate the synchronzation operations from the other operations.

example :
[10/Jul/2007:15:29:34 +0200] ADD conn=-1 op=1314 msgID=1315 dn="cn=Natascha Pfifferling463, ou=Human Resources, dc=example,dc=com" type=synchronization
[10/Jul/2007:15:29:34 +0200] ADD conn=-1 op=1314 msgID=1315 result="Success" etime=98

I could not find any unit test for the access and audit log and decided it was too
complex to create new ones compared to the simplicity of this change...

 opendj-sdk/opends/resource/config/config.ldif

@@ -520,6 +520,7 @@
ds-cfg-log-file: logs/access
ds-cfg-log-file-mode: 640
ds-cfg-suppress-internal-operations: true
ds-cfg-suppress-synchronization-operations: false
ds-cfg-asynchronous-writes: true
ds-cfg-rotation-policy-dn: cn=24 Hours Time Limit Rotation Policy,cn=Log Rotation Policies,cn=config
ds-cfg-rotation-policy-dn: cn=Size Limit Rotation Policy,cn=Log Rotation Policies,cn=config
@@ -536,6 +537,7 @@
ds-cfg-log-file: logs/audit
ds-cfg-log-file-mode: 640
ds-cfg-suppress-internal-operations: true
ds-cfg-suppress-synchronization-operations: false
ds-cfg-asynchronous-writes: true
ds-cfg-rotation-policy-dn: cn=24 Hours Time Limit Rotation Policy,cn=Log Rotation Policies,cn=config
ds-cfg-rotation-policy-dn: cn=Size Limit Rotation Policy,cn=Log Rotation Policies,cn=config

 opendj-sdk/opends/resource/schema/02-config.ldif

@@ -415,6 +415,10 @@
  NAME 'ds-cfg-suppress-internal-operations'
  SYNTAX 1.3.6.1.4.1.1466.115.121.1.7 SINGLE-VALUE
  X-ORIGIN 'OpenDS Directory Server' )
attributeTypes: ( 1.3.6.1.4.1.26027.1.1.436
  NAME 'ds-cfg-suppress-synchronization-operations'
  SYNTAX 1.3.6.1.4.1.1466.115.121.1.7 SINGLE-VALUE
  X-ORIGIN 'OpenDS Directory Server' )
attributeTypes: ( 1.3.6.1.4.1.26027.1.1.124 NAME 'ds-cfg-syntax-class'
  SYNTAX 1.3.6.1.4.1.1466.115.121.1.15 SINGLE-VALUE
  X-ORIGIN 'OpenDS Directory Server' )
@@ -1597,7 +1601,8 @@
  X-ORIGIN 'OpenDS Directory Server' )
objectClasses: ( 1.3.6.1.4.1.26027.1.2.23 NAME 'ds-cfg-access-logger'
  SUP ds-cfg-logger
  STRUCTURAL MAY ( ds-cfg-suppress-internal-operations )
  STRUCTURAL MAY ( ds-cfg-suppress-internal-operations $ 
  ds-cfg-suppress-synchronization-operations )
  X-ORIGIN 'OpenDS Directory Server' )
objectClasses: ( 1.3.6.1.4.1.26027.1.2.24 NAME 'ds-cfg-error-logger'
  SUP ds-cfg-logger

 opendj-sdk/opends/src/admin/defn/org/opends/server/admin/std/AccessLogPublisherConfiguration.xml

@@ -41,6 +41,8 @@
  <adm:property name="suppress-internal-operations">
    <adm:synopsis>
      Omit access messages generated by internal operations.
      Except for Synchronization operations that are controlled 
      by the ds-cfg-suppress-synchronization-operations property.
    </adm:synopsis>
    <adm:default-behavior>
      <adm:defined>
@@ -59,4 +61,25 @@
      </ldap:attribute>
    </adm:profile>
  </adm:property>
  <adm:property name="suppress-synchronization-operations">
    <adm:synopsis>
      Omit access messages generated by synchronization operations.
    </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:oid>1.3.6.1.4.1.26027.1.1.436</ldap:oid>
        <ldap:name>ds-cfg-suppress-synchronization-operations</ldap:name>
      </ldap:attribute>
    </adm:profile>
  </adm:property>
</adm:managed-object>

 opendj-sdk/opends/src/server/org/opends/server/api/AccessLogPublisher.java

@@ -52,6 +52,12 @@
   */
  protected boolean suppressInternalOperations = true;

  /**
   * Indicates if synchronization operations should be omited in the
   * messages logged by this publisher.
   */
  protected boolean suppressSynchronizationOperations = false;



  /**

 opendj-sdk/opends/src/server/org/opends/server/loggers/TextAccessLogPublisher.java

@@ -183,6 +183,8 @@
    }

    suppressInternalOperations = config.isSuppressInternalOperations();
    suppressSynchronizationOperations =
      config.isSuppressSynchronizationOperations();

    currentConfig = config;

@@ -277,6 +279,8 @@
     ArrayList<String> messages = new ArrayList<String>();

     suppressInternalOperations = config.isSuppressInternalOperations();
     suppressSynchronizationOperations =
       config.isSuppressSynchronizationOperations();

     File logFile = getFileForPath(config.getLogFile());
     FileNamingPolicy fnPolicy = new TimeStampNaming(logFile);
@@ -418,6 +422,7 @@
  public void logConnect(ClientConnection clientConnection)
  {
    long connectionID = clientConnection.getConnectionID();

    if (connectionID < 0 && suppressInternalOperations)
    {
      return;
@@ -491,10 +496,24 @@
  public void logAbandonRequest(AbandonOperation abandonOperation)
  {
    long connectionID = abandonOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (abandonOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }

    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
@@ -508,6 +527,8 @@
    buffer.append(abandonOperation.getMessageID());
    buffer.append(" idToAbandon=");
    buffer.append(abandonOperation.getIDToAbandon());
    if (abandonOperation.isSynchronizationOperation())
      buffer.append(" type=synchronization");

    writer.writeRecord(buffer.toString());
  }
@@ -522,10 +543,24 @@
  public void logAbandonResult(AbandonOperation abandonOperation)
  {
    long connectionID = abandonOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (abandonOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -572,10 +607,24 @@
  public void logAddRequest(AddOperation addOperation)
  {
    long connectionID = addOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (addOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -589,6 +638,9 @@
    buffer.append(" dn=\"");
    addOperation.getRawEntryDN().toString(buffer);
    buffer.append("\"");
    if (addOperation.isSynchronizationOperation())
      buffer.append(" type=synchronization");


    writer.writeRecord(buffer.toString());
  }
@@ -604,10 +656,24 @@
  public void logAddResponse(AddOperation addOperation)
  {
    long connectionID = addOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (addOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -660,10 +726,24 @@
  public void logBindRequest(BindOperation bindOperation)
  {
    long connectionID = bindOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (bindOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -693,6 +773,9 @@
    buffer.append(" dn=\"");
    bindOperation.getRawBindDN().toString(buffer);
    buffer.append("\"");
    if (bindOperation.isSynchronizationOperation())
      buffer.append(" type=synchronization");


    writer.writeRecord(buffer.toString());
  }
@@ -708,10 +791,24 @@
  public void logBindResponse(BindOperation bindOperation)
  {
    long connectionID = bindOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (bindOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -794,10 +891,24 @@
  public void logCompareRequest(CompareOperation compareOperation)
  {
    long connectionID = compareOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (compareOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -812,6 +923,9 @@
    compareOperation.getRawEntryDN().toString(buffer);
    buffer.append("\" attr=");
    buffer.append(compareOperation.getAttributeType());
    if (compareOperation.isSynchronizationOperation())
      buffer.append(" type=synchronization");


    writer.writeRecord(buffer.toString());
  }
@@ -827,10 +941,24 @@
  public void logCompareResponse(CompareOperation compareOperation)
  {
    long connectionID = compareOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (compareOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -882,10 +1010,24 @@
  public void logDeleteRequest(DeleteOperation deleteOperation)
  {
    long connectionID = deleteOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (deleteOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -899,6 +1041,9 @@
    buffer.append(" dn=\"");
    deleteOperation.getRawEntryDN().toString(buffer);
    buffer.append("\"");
    if (deleteOperation.isSynchronizationOperation())
      buffer.append(" type=synchronization");



    writer.writeRecord(buffer.toString());
@@ -915,10 +1060,24 @@
  public void logDeleteResponse(DeleteOperation deleteOperation)
  {
    long connectionID = deleteOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (deleteOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -971,10 +1130,24 @@
  public void logExtendedRequest(ExtendedOperation extendedOperation)
  {
    long connectionID = extendedOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (extendedOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -988,6 +1161,9 @@
    buffer.append(" oid=\"");
    buffer.append(extendedOperation.getRequestOID());
    buffer.append("\"");
    if (extendedOperation.isSynchronizationOperation())
      buffer.append(" type=synchronization");


    writer.writeRecord(buffer.toString());
  }
@@ -1004,10 +1180,24 @@
  public void logExtendedResponse(ExtendedOperation extendedOperation)
  {
    long connectionID = extendedOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (extendedOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -1062,10 +1252,24 @@
  public void logModifyRequest(ModifyOperation modifyOperation)
  {
    long connectionID = modifyOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (modifyOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -1079,6 +1283,9 @@
    buffer.append(" dn=\"");
    modifyOperation.getRawEntryDN().toString(buffer);
    buffer.append("\"");
    if (modifyOperation.isSynchronizationOperation())
      buffer.append(" type=synchronization");


    writer.writeRecord(buffer.toString());
  }
@@ -1095,10 +1302,24 @@
  public void logModifyResponse(ModifyOperation modifyOperation)
  {
    long connectionID = modifyOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // this is an internal operation
      if (modifyOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -1151,10 +1372,24 @@
  public void logModifyDNRequest(ModifyDNOperation modifyDNOperation)
  {
    long connectionID = modifyDNOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (modifyDNOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -1178,6 +1413,9 @@
      buffer.append(" newSuperior=\"");
      newSuperior.toString(buffer);
    }
    if (modifyDNOperation.isSynchronizationOperation())
      buffer.append(" type=synchronization");


    writer.writeRecord(buffer.toString());
  }
@@ -1195,10 +1433,24 @@
  public void logModifyDNResponse(ModifyDNOperation modifyDNOperation)
  {
    long connectionID = modifyDNOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (modifyDNOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -1250,10 +1502,24 @@
  public void logSearchRequest(SearchOperation searchOperation)
  {
    long connectionID = searchOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (searchOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -1290,6 +1556,9 @@

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


    writer.writeRecord(buffer.toString());
  }
@@ -1338,10 +1607,24 @@
  public void logSearchResultDone(SearchOperation searchOperation)
  {
    long connectionID = searchOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (searchOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -1399,10 +1682,24 @@
  public void logUnbind(UnbindOperation unbindOperation)
  {
    long connectionID = unbindOperation.getConnectionID();
    if (connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (unbindOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    StringBuilder buffer = new StringBuilder(50);
    buffer.append("[");
    buffer.append(TimeThread.getLocalTime());
@@ -1413,6 +1710,9 @@
    buffer.append(unbindOperation.getOperationID());
    buffer.append(" msgID=");
    buffer.append(unbindOperation.getMessageID());
    if (unbindOperation.isSynchronizationOperation())
      buffer.append(" type=synchronization");


    writer.writeRecord(buffer.toString());
  }

 opendj-sdk/opends/src/server/org/opends/server/loggers/TextAuditLogPublisher.java

@@ -167,6 +167,8 @@
    }

    suppressInternalOperations = config.isSuppressInternalOperations();
    suppressSynchronizationOperations =
      config.isSuppressSynchronizationOperations();

    currentConfig = config;

@@ -248,6 +250,8 @@
     ArrayList<String> messages = new ArrayList<String>();

     suppressInternalOperations = config.isSuppressInternalOperations();
     suppressSynchronizationOperations =
       config.isSuppressSynchronizationOperations();

     File logFile = getFileForPath(config.getLogFile());
     FileNamingPolicy fnPolicy = new TimeStampNaming(logFile);
@@ -274,7 +278,7 @@

       if(currentWriter instanceof MultifileTextWriter)
       {
         MultifileTextWriter mfWriter = (MultifileTextWriter)writer;
         MultifileTextWriter mfWriter = (MultifileTextWriter)currentWriter;

         mfWriter.setNamingPolicy(fnPolicy);
         mfWriter.setFilePermissions(perm);
@@ -435,10 +439,24 @@
  public void logAddResponse(AddOperation addOperation)
  {
    long connectionID = addOperation.getConnectionID();
    if(connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (addOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    ResultCode code = addOperation.getResultCode();

    if(code == SUCCESS)
@@ -554,10 +572,24 @@
  public void logDeleteResponse(DeleteOperation deleteOperation)
  {
    long connectionID = deleteOperation.getConnectionID();
    if(connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (deleteOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    ResultCode code = deleteOperation.getResultCode();

    if(code == SUCCESS)
@@ -618,10 +650,24 @@
  public void logModifyResponse(ModifyOperation modifyOperation)
  {
    long connectionID = modifyOperation.getConnectionID();
    if(connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (modifyOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    ResultCode code = modifyOperation.getResultCode();

    if(code == SUCCESS)
@@ -705,10 +751,24 @@
  public void logModifyDNResponse(ModifyDNOperation modifyDNOperation)
  {
    long connectionID = modifyDNOperation.getConnectionID();
    if(connectionID < 0 && suppressInternalOperations)
    if (connectionID < 0)
    {
      // This is an internal operation.
      if (modifyDNOperation.isSynchronizationOperation())
      {
        if (suppressSynchronizationOperations)
    {
      return;
    }
      }
      else
      {
        if (suppressInternalOperations)
        {
          return;
        }
      }
    }
    ResultCode code = modifyDNOperation.getResultCode();

    if(code == SUCCESS)