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.
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.
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:
LINK: When Identity Synchronization for Windows synchronizes a new Directory Server user to Windows, the Windows Connector sends a Link Action to the Directory Server Connector after the entry is created. This Link Action contains the user's Windows GUID, which is written to the user's Directory Server entry. Link Actions are only sent from a Windows Connector to the Directory Server Connector.
UNKNOWN: When a Windows Connector detects a change to a user, the corresponding action is assigned the Unknown type until the connector determines the type of the action by comparing it with the object cache.
REFRESH: Indicates resynchronization operations resulting from running the idsync resync command. Actions of this type hold the current value of all user attributes and do not correspond to a detected change in a user entry.
SENTINEL: Signals that all source actions are sent during the idsync resync operation. The source connector during a idsync resync operation sends one Sentinel action for each Synchronization User List that is processed, to signal that all users in that Synchronization User List are sent. This is the only action type that does not correspond to a user entry.
Attributes from the user entry are also included when the action is logged. These attributes are divided into two types: data attributes and other attributes. Data attributes correspond to attributes that are always synchronized, for example, userpassword, while the other attributes are required, for example, objectguid or pwdlastset. Other attributes are sometimes referred to as meta attributes.
During processing, an action is passed through three different layers of the connector: accessor, controller, and agent. Each layer has different responsibilities:
Accessor: Interfaces directly with a directory source over protocols such as LDAP. There are separate accessor implementations for Directory Server, Active Directory, and Windows NT.
Controller: A connector component that interfaces with the agent and accessor components. The controller performs key synchronization-related tasks such as determining a user's membership in a Synchronization User List, searching for and linking equivalent user entries, and detecting changes to users by comparing current user entries with the previous versions stored in the object cache. (The term adapter refers to the combination of the accessor and controller layers.)
Agent: Interfaces with Message Queue and translates attributes between their Directory Server names and Windows names. Distributes configuration received over Message Queue to the other connector layers.
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.
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:
[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) |
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.
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.
This entry can be manipulated over LDAP while Directory Server is running, or by editing the dse.ldif file when Directory Server is not running.
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:
nsslapd-infolog-area: 65536
nsslapd-infolog-level: 1