Sun Java System Identity Synchronization for Windows 6.0 Deployment Planning Guide

Audit Logging and Action IDs

Before enabling debug logging, make sure that setting the audit log level to FINEST does not produce the desired level of information. When a new log level setting is saved in the console, it is immediately propagated to every component, and messages at that log level and above will be logged to the central log.


Note –

Changes to the log level are not propagated to subcomponents, that is, the Directory Server Plugin, the Windows NT Change Detector, and the Windows NT Password Filter DLL, until the next configuration change is saved. To propagate a new log level setting to the subcomponents, make any minor edit to the configuration, undo the edit, and then save the configuration.


Actions

When an Identity Synchronization for Windows Connector detects a change to a user entry, it uses an action to represent this change as it travels through Identity Synchronization for Windows. Each action includes a type such as CREATE, MODIFY, or DELETE, and enough attributes from the user entry to allow the destination connector to synchronize the change. The type of an action appears in log entries can be one of the following:

Connector Layers - Accessor, Controller, and Agent

During processing, an action is passed through three different layers of the connector: accessor, controller, and agent. Each layer has different responsibilities:

For higher performance, the connector processes many actions at once, so log messages for different actions are interleaved. When the processing of an action is complete, the source of the action (that is, the Accessor or Message Queue) is notified by an acknowledgement. After an action is acknowledged, the source of the action is no longer responsible for re-delivering the action in the event of a failure. The action path that detected changes from the directory source to Message Queue is known as the inbound path. The action path that applies changes from Message Queue to the directory source is known as the outbound path. These action paths are summarized in the following figure.

Figure C–1 Action Paths

Action Paths

To illustrate how this applies to log messages, a sample message from the central audit.log, when user John Test's password was changed, is given below:

[01/Nov/2004:07:17:56.082 -0600] FINE  54  CNN101 connectors-us  
"The controller has received the following inbound action from the accessor: 
Type: UNKNOWN {Data Attrs: } 
{Other Attrs: cn: John Test dn: CN=John Test,CN=Users,DC=gt,DC=com 
objectclass: top, person, organizationalPerson, 
user objectguid: coFNlF3ePUWC5Vm32GENfg== pwdlastset: 127437958757034806 
samaccountname: jtest sn: Test usnchanged: 313464 whenchanged: 20041101151755.0Z}." 
(Action ID=CNN101-FFEF4A8986-206, SN=1)

         

This message was logged as the Accessor passed a detected change along the inbound path to the Controller. The type of the action is UNKNOWN because the Controller has not yet compared the action with its object cache database. There are no data attributes in the entry because password values cannot be extracted from Active Directory. Instead, the pwdlastset attribute is used to detect if the password has changed. The action also includes a unique ID that can be used to track it through the system. A monotonically increasing sequence number (the SN value) also appears in the log entry. In rare circumstances where messages logged at different connectors arrive out-of-order at the Central Logger, the sequence number can be used to correctly order the messages. However, sequence numbers might not always increase by one. This action can be tracked through the log by searching for the unique ID ID=CNN101-FFEF4A8986-206:


bash-2.05# grep 'ID=CNN101-FFEF4A8986-206' audit.log
[01/Nov/2004:07:17:56.082 -0600] FINE    54  
CNN101 connectors-us  "The controller has received the following inbound action
from the accessor: Type: UNKNOWN {Data Attrs: } 
{Other Attrs: cn: John Test dn: CN=John Test,CN=Users,DC=gt,DC=com 
objectclass: top, person, organizationalPerson, 
user objectguid: coFNlF3ePUWC5Vm32GENfg== pwdlastset: 127437958757034806 
samaccountname: jtest sn: Test usnchanged: 313464 whenchanged: 20041101151755.0Z}." 
(Action ID=CNN101-FFEF4A8986-206, SN=1)
[01/Nov/2004:07:17:56.307 -0600] FINE    51  


CNN101 connectors-us  
"The agent has received the following inbound action from the controller: 
Type: MODIFY SUL: GT_USERS {Data Attrs: } 
{Other Attrs: cn: John Test dn: CN=John Test,CN=Users,DC=gt,DC=com 
objectclass: top, person, organizationalPerson, 
user objectguid: coFNlF3ePUWC5Vm32GENfg== pwdlastset: 127437958757034806 
samaccountname: jtest sn: Test usnchanged: 313464 
whenchanged: 20041101151755.0Z passwordchanged: TRUE}." 
(Action ID=CNN101-FFEF4A8986-206, SN=4)


[01/Nov/2004:07:17:56.320 -0600] INFO    51  
CNN101 connectors-us  
"The agent is sending the following inbound action to MQ: 
Type: MODIFY SUL: GT_USERS {Data Attrs: } 
{Other Attrs: cn: John Test dn: CN=John Test,CN=Users,DC=gt,DC=com 
objectclass: top, person, organizationalPerson, 
user dspswuserlink: coFNlF3ePUWC5Vm32GENfg== pwdlastset: 127437958757034806 
samaccountname: jtest sn: Test usnchanged: 313464 
whenchanged: 20041101151755.0Z passwordchanged: TRUE}." 
(Action ID=CNN101-FFEF4A8986-206, SN=6)

         
[01/Nov/2004:07:17:56.448 -0600] FINE    16  
CNN100 connectors-us  "The agent has received an outbound action from MQ: 
Type: MODIFY SUL: GT_USERS {Data Attrs: } 
{Other Attrs: cn: John Test dn: CN=John Test,CN=Users,DC=gt,DC=com 
objectclass: top, person, organizationalPerson, 
user dspswuserlink: coFNlF3ePUWC5Vm32GENfg== pwdlastset: 127437958757034806 
samaccountname: jtest sn: Test usnchanged: 313464 
whenchanged: 20041101151755.0Z passwordchanged: TRUE}." 
(Action ID=CNN101-FFEF4A8986-206, SN=7)


[01/Nov/2004:07:17:56.462 -0600] FINE    16  
CNN100 connectors-us  
"The controller has received the following outbound action from the agent:
Type: MODIFY SUL: GT_USERS {Data Attrs: } 
{Other Attrs: cn: John Test dn: CN=John Test,CN=Users,DC=gt,DC=com 
objectclass: top, person, organizationalPerson,
user dspswuserlink: coFNlF3ePUWC5Vm32GENfg== pwdlastset: 127437958757034806 
samaccountname: jtest sn: Test usnchanged: 313464 
whenchanged: 20041101151755.0Z passwordchanged: TRUE}." 
(Action ID=CNN101-FFEF4A8986-206, SN=8)


[01/Nov/2004:07:17:56.549 -0600] FINE    40  
CNN100 connectors-us  
"Applying outbound action to Accessor" 
(Action ID=CNN101-FFEF4A8986-206, SN=9)


[01/Nov/2004:07:17:56.557 -0600] FINE    40  
CNN100 connectors-us  
"The accessor has received the following outbound action from the controller: 
Type: MODIFY SUL: GT_USERS {Data Attrs: } {Other Attrs: cn: John Test 
objectclass: top, person, organizationalPerson, 
user dspswuserlink: coFNlF3ePUWC5Vm32GENfg== pwdlastset: 127437958757034806 
samaccountname: jtest sn: Test usnchanged: 313464 
whenchanged: 20041101151755.0Z passwordchanged: TRUE 
dn: uid=jtest,ou=People, dc=gt,dc=com}." (Action ID=CNN101-FFEF4A8986-206, SN=10)


[01/Nov/2004:07:17:56.640 -0600] FINE    40  
CNN100 connectors-us  
"Successfully modified user 'uid=jtest,ou=People, dc=gt,dc=com', 
action=Type: MODIFY SUL: GT_USERS {Data Attrs: [REPL dspswvalidate: true]}." 
(Action ID=CNN101-FFEF4A8986-206, SN=11)


[01/Nov/2004:07:17:56.657 -0600] INFO    40  
CNN100 connectors-us  
"Successfully modified user uid=jtest,ou=People, dc=gt,dc=com" 
(Action ID=CNN101-FFEF4A8986-206, SN=12)

Most log entries dealing with an action will include the Action ID, but some log entries will not. In these cases, the log entry without the Action ID is usually close to log messages that do include the ID. For example, a summary of the LDAP modification for the above password update appears between two other log messages:


[01/Nov/2004:07:17:56.557 -0600] FINE    40  
CNN100 connectors-us  
"The accessor has received the following outbound action from the controller: 
Type: MODIFY SUL: GT_USERS {Data Attrs: } 
{Other Attrs: cn: John Test objectclass: top, person, organizationalPerson, 
user dspswuserlink: coFNlF3ePUWC5Vm32GENfg== pwdlastset: 127437958757034806 
samaccountname: jtest sn: Test usnchanged: 313464 
whenchanged: 20041101151755.0Z passwordchanged: 
TRUE dn: uid=jtest,ou=People, dc=gt,dc=com}." 
(Action ID=CNN101-FFEF4A8986-206, SN=10)


[01/Nov/2004:07:17:56.567 -0600] FINE    40  
CNN100 connectors-us  "LDAP Modify Request: 
[REPLACE dspswvalidate: true] [REPLACE dspswloop: true] [REPLACE dspswloop: ] "


[01/Nov/2004:07:17:56.640 -0600] FINE    40  
CNN100 connectors-us  
"Successfully modified user 'uid=jtest,ou=People, dc=gt,dc=com', action=Type: 
MODIFY SUL: GT_USERS {Data Attrs: [REPL dspswvalidate: true]}." 
(Action ID=CNN101-FFEF4A8986-206, SN=11)

         

Note –

All messages that appear in the error log file also appear in the audit log file, to facilitate correlation of events leading up to the error or warning message.

The central log files are an aggregation of the individual component logs. As long as a connector can access Message Queue, all messages written to the local logs will also be written to the central log.

A special central log file is used for idsync resync operations. The information in this log is only available on the Core machine in the logs/central/resync.log file. During a resynchronization operation, some information is also logged to the audit log, so the Action ID may be required to correlate log entries between the two files.


Directory Server Plugin

Increasing the global log level alone might not display all the log entries from the Directory Server Plugin. Editing Directory Server's cn=config entry may also be required. To enable more informational logging, set the following attributes on Directory Server's cn=config entry.


Note –

nsslapd-infolog-area is a bit mask entry. If it already has a value, then bit-wise OR in the 16th least significant bit into the value.


To enable additional logging, set the attributes on Directory Server's cn=config entry as follows: