Содержащиеся в
Найти другие документыРесурсы поддержки | Загрузить это руководство в формате PDF (2497 КБ)
Appendix C Logging and DebuggingThis appendix expands on the logging and troubleshooting information available in the Sun Java System Directory Server Enterprise Edition 6.3 Troubleshooting Guide by describing how to use audit and debug logging to isolate problems in the system. This appendix includes: Audit Logging and Action IDsBefore 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. ActionsWhen 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 AgentDuring 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
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:
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 PluginIncreasing 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:
Debug LoggingMost of the Identity Synchronization for Windows components have debug logging capability. This section describes how to enable debug logging for each component. Using debug logging to isolate a problem can be a time-consuming process. Be sure to read Chapter 7, Troubleshooting Identity Synchronization for Windows, in Sun Java System Directory Server Enterprise Edition 6.1 Troubleshooting Guide before using this method. In Java ComponentsTo enable debug logging in one of the Java components (connector, System Manager, or Central Logger), edit the process's command line in the WatchList.properties file to include the -Dcom.sun.directory.wps.flags.Flags.DBG=true flag, and restart the Identity Synchronization for Windows daemon (on Solaris) or service (on Windows). For example, debug logging for the CNN101 Connector has been enabled in the following example. The existing entry for the CNN101 Connector in the /var/opt/SUNWisw/resources/WatchList.properties file is shown below.
Note – The idsync printstat command provides information about the Connector ID and the installation location, which can be used to find the correct entry in the WatchList.properties list. In the following example, the command line entry for this connector has been edited to include the special debug option. It is safest to include this option as the first JVM option.
After enabling this option, stop and start the Identity Synchronization for Windows daemon (on Solaris) or service (on Windows) so that the changes take effect. To prevent conflicts with Message Queue, wait thirty seconds after stopping the Identity Synchronization for Windows daemon or service before restarting it. Once the process starts, it will write three new logs, logs/CNN101/debug.log, logs/CNN101/debugErrors.log, andogs/CNN101/resyncDebug.log.
These log levels can be changed by editing the Log.properties files. The changes will be reflected after a restart. Note – All messages that appear in the audit log file also appear in the debug log file to facilitate correlation of events between the logs. In the InstallerThe installer and uninstaller can be configured to write extra debugging information to the installer log file, for example, Identity_Synchronization_for_Windows_install-20041025035143.log, by setting the ISW_DEBUG_INSTALL environment variable to true before starting the installer.
Note – Secure information such as passwords might appear in the installer log file when debug logging is enabled. In the ConsoleThe console logs some information to the central log, but most information is only logged if the console is started with the -D option to enable debug logging. The -D option accepts a single argument which controls the amount of logging to generate. It varies from 1 (least) to 9 (most). By default, the logging information is only written to stderr, but it can also be redirected to a file using the -f option, for example: bash-2.05# ./startconsole -D 7 -f /tmp/console.log Windows NT Change DetectionWhen you start Windows NT Connector for the first time, with no existing object cache present, the corresponding Java process’s memory usage is approximately 26 to 30 MB. However, the Windows NT Connector's memory usage can easily reach 100 MB during normal operations. The Windows NT Connector periodically polls the Windows NT subcomponents, that is, Identity Synchronization for Windows NT Change Detector Service and the Identity Synchronization for Windows Password Filter DLL for changes. After the connector retrieves changes from a subcomponent, the connector processes the change and based on the configuration, it will or will not send the change over Message Queue. After the connector finishes processing the change, it removes the change from the subcomponents. If the Windows NT Connector is unavailable for a longer period of time, then the subcomponents can accumulate a significant number of changes in memory. A typical change record requires less than 100 bytes of memory, so 10 MB of memory can accommodate 100,000 changes. However, this scenario is not likely to occur on Windows NT. Both the Change Detector service and the Password Filter DLL service maintain some internal counters. You can use these counters (with the connector's log file) to determine how far behind the connector is with change processing compared to the subcomponents. For example, the following is a user creation entry in the connector's log:
The important fields in this entry are:
"PfLastAckedChangeNumber"=hex:05,00,00,00,00,00,00,00
"PfLastAckedChangeTime"=hex:54,64,86,41
"PfHighestChangeNumber"=hex:05,00,00,00,00,00,00,00
"PfHighestChangeTime"=hex:52,64,86,41
Where:
[01/Nov/2004:10:30:31.802 -0600]
INFO 18 CNN102 example-wnt
"The agent is sending the following inbound action to MQ:
Type: MODIFY SUL: NT {Data Attrs: }
{Other Attrs: sn: test cn: Jane Test user_rid: 1004
dspswuserlink: RID=1004+DOMAIN=EXAMPLE subcomp_src:
NT_CHANGE_DETECTOR usnchanged: 19}."
(Action ID=CNN102-FFF4EFF25B-1162, SN=0)
In this example, the subcomp_src is set to NT_CHANGE_DETECTOR and the following counters are displayed in the same registry entry mentioned previously: "LastProcessedSecLogRecordNumber"=dword:0000001b
"LastProcessedSecLogTimeStamp"=dword:418664a7
"HighestChangeNumber"=dword:00000013
In this example, the Change Detector does not show the last acknowledged changenumber, but the value of HighestChangeNumber is the same as the value in the log entry. To determine (approximately) how many unprocessed changes there are in the Change Detector, check the last log entry in which the subcomp_src is set to NT_CHANGE_DETECTOR, and then compare the usnchanged value in the log entry with the HighestChangeNumber in the registry. The LastProcessedSecLog counter refers to the last-processed entry in the system's security log. The psloglist.exe in the PsTools software bundle from http://www.sysinternals.com/ facilitates listing the contents of the security log and printing out the security log numbers. For example,
In this example, the log record number is 27 (which corresponds to the value in LastProcessedSecLogRecordNumber - 0x1b). Changing Central Logs File LocationThe location of the central logs can be changed using the console or the Log Configuration tab. Specify the location in the Write log file to directory field. Figure C–2 Log Configuration Tab
Changing Component Logs File LocationThe location of logs for Java components, that is, System Manager, Central Logger, and Connectors is changed by modifying the com.sun.directory.wps.logging.directory property in the WatchList.properties file. In the following example, the logging directory for the Active Directory Connector is changed from /var/opt/SUNWisw/logs/CNN101 to /export/isw/logs/adConnector:
Note – The idsync printstat command provides information about the Connector ID and the installation location that can be used to locate the correct entry in the WatchList.properties file. To change the logging directory, the command line entry for this connector must be edited as follows:
After this change is made, the Identity Synchronization for Windows daemon (on Solaris) or service (on Windows) where the connector is running is stopped and restarted for changes to take effect. Isolating Problems in Directory ServerFor details on concepts and configuration information related to logging options in Directory Server, see the following documents:
Isolating Problems in Message QueueFor information on understanding and configuring the Message Queue Broker's log, see the Message Queue Administration Guide (http://docs.sun.com/db/doc/817-3727). Isolating Problems in Active DirectoryActive Directory logs information to the Directory Service event log on each domain controller. To increase the amount of logging, change the Windows registry entries. There are several diagnostic values under the HKEY_LOCAL_MACHINE\\SYSTEM\\CurrentControlSet\\Services\\NTDS\\Diagnostics key. They default to 0 = no logging; other permitted values are:
|
|||||||||||||||||||||||||||||||||||||||||||||||||