Event Tracing in LDAP Applications

Windows Server 2008 and Windows Vista introduce Event Tracing for applications that use Lightweight Directory Access Protocol. Certain areas of the LDAP Provider have an underlying implementation that is complex or that involves a sequence of steps that makes diagnosis of problems in these areas more difficult. Event Tracing can be a valuable troubleshooting tool.

To turn on LDAP client tracing, create the following registry key:

HKEY_LOCAL_MACHINE\System\CurrentControlSet\Services\ldap\Tracing\ProcessName

ProcessName is the full name of the process that you want to trace, including its extension (for example, "Svchost.exe"). Inside this key, you can place an optional value of type DWORD that is named "PID". If this optional value is set to a process ID, only the instance of the application with this process ID will be traced.

To start a tracing session, execute the following command:

tracelog.exe -start SessionName -guid #GUIDforLDAPTracingProvider -f FileName -flag <TraceFlags>

SessionName is an arbitrary identifier that is used to label the tracing session (you will need to refer to this session name later when you stop the tracing session). The GUID for the LDAP tracing provider is "099614a5-5dd7-4788-8bc9-e29f43db28fc". FileName specifies the log file to which events will be written. TraceFlags should be one or more of the following values.

Flag nameFlag valueFlag description

DEBUG_SEARCH

0x00000001

Logs search requests and the parameters passed to them. Responses are not logged here, only the search requests. (Responses to search requests can be logged by using DEBUG_SPEWSEARCH.)

Windows Server 2008 and Windows Vista:  The flag name was DEBUG_TRACE1.

DEBUG_WRITE

0x00000002

Logs write requests and the parameters passed to them. This includes the operations: add, delete, modify, and extended.

Windows Server 2008 and Windows Vista:  The flag name was DEBUG_TRACE2.

DEBUG_REFCNT

0x00000004

Logs reference counting data and operations for connections and requests.

DEBUG_HEAP

0x00000008

Logs all memory allocations and memory frees.

DEBUG_CACHE

0x00000010

Logs cache activity. This includes adds, removes, hits, misses, and so on.

DEBUG_SSL

0x00000020

Logs SSL information and errors.

DEBUG_SPEWSEARCH

0x00000040

Logs all server responses to search requests. This includes attributes requested, as well as all data that was received.

Windows Server 2008 and Windows Vista:  Only available in debug builds.

DEBUG_SERVERDOWN

0x00000080

Logs server down and connection errors.

DEBUG_CONNECT

0x00000100

Logs data related to establishing a connection.

Note  Other connection related data will be logged in DEBUG_CONNECTION.
 

DEBUG_RECONNECT

0x00000200

Logs automatic reconnect activity. This includes reconnect attempts, failures, and related errors.

DEBUG_RECEIVEDATA

0x00000400

Logs info related to receiving messages from the server. This includes events such as response received from server, waiting on response from server, and so on.

DEBUG_BYTES_SENT

0x00000800

Logs all data sent by the LDAP client to the server. This is essentially packet logging, but it always logs unencrypted data. (If a packet is sent over SSL, this logs the unencrypted packet.) This can be verbose and is probably best used on its own (or with DEBUG_BYTES_RECEIVED).

DEBUG_EOM

0x00001000

Logs events related to reaching the end of a message list. This includes things like message list cleared and so on.

DEBUG_BER

0x00002000

Logs Basic Encoding Rules (BER) operations and errors. This includes problems with encoding, buffer size problems, and so on.

DEBUG_OUTMEMORY

0x00004000

Logs failures to allocate memory. Generally logs any failure to compute the required memory as well, for example, overflow when computing the required buffer size.

DEBUG_CONTROLS

0x00008000

Logs data related to controls. This includes inserting controls, problems with controls, mandatory controls on a connection, and so on.

DEBUG_BYTES_RECEIVED

0x00010000

Logs all data received by the LDAP client. This is essentially packet logging, but it always logs unencrypted data. (If a packet is sent over SSL, this logs the unencrypted packet.) This can be verbose and is probably best used on its own (or with DEBUG_BYTES_SENT).

DEBUG_CLDAP

0x00020000

Logs events specific to UDP and connectionless LDAP.

DEBUG_FILTER

0x00040000

Logs events and errors encountered when constructing a search filter.

Note  This only logs client events during filter construction. No responses from the server regarding a filter are included here.
 

DEBUG_BIND

0x00080000

Logs bind events and errors. This includes negotiation information, bind success, bind fail, and so on.

DEBUG_NETWORK_ERRORS

0x00100000

Logs general network errors. This includes send and receive errors.

Note  If a connection is lost or the server cannot be reached, DEBUG_SERVERDOWN is the preferred tag.
 

DEBUG_VERBOSE

0x00200000

Logs general messages. This should be used for any messages that tend to generate a large amount of output, for example: end of message reached, server has not responded yet, and so on. This is also useful for generic messages.

Windows Server 2008 and Windows Vista:  The flag name was DEBUG_SCRATCH.

DEBUG_PARSE

0x00400000

Logs general message and packet parsing and encoding events and errors.

DEBUG_REFERRALS

0x00800000

Logs data about referrals and chasing referrals.

DEBUG_REQUEST

0x01000000

Logs tracking of requests.

DEBUG_CONNECTION

0x02000000

Logs general connection data and errors.

DEBUG_INIT_TERM

0x04000000

Logs module initialization and cleanup (DLL Main, and so on).

DEBUG_API_ERRORS

0x08000000

Supports logging improper use of the API, for example, if bind is called twice on the same connection.

DEBUG_ERRORS

0x10000000

Logs general errors. Most fall into one of the following categories: module initialization errors, SSL errors, or overflow or underflow errors.

 

You can combine flags by combining the appropriate bits in the TraceFlags argument. For example, to specify the DEBUG_SEARCH and DEBUG_CACHE flags, the appropriate TraceFlags value would be 0x00000011.

To terminate tracing, run the following command:

tracelog.exe -stop SessionName

In this example, SessionName is the same name as the one that was provided with the command that started the tracing section.

Example Scenario

Imagine that an administrator sees an unexpected error in an application that sets passwords for user accounts, so the administrator decides to enable tracing for App1.exe. They would take the following steps to fix the problem using event tracing.

  1. Create the registry key

    HKEY_LOCAL_MACHINE\System\CurrentControlSet\Services\ldap\Tracing\App1.exe

    and then start a tracing session using the following command:

    tracelog.exe -start ldaptrace -guid #099614a5-5dd7-4788-8bc9-e29f43db28fc -f .\ldap.etl -flag 0x80000

  2. After this command has started, DEBUG_BIND tracing messages will be written to .\ldap.etl. Execute App1.exe and reproduce the unexpected behavior.

  3. Shut down the tracing session as follows:

    tracelog.exe -stop ldaptrace

  4. Delete the registry key

    HKEY_LOCAL_MACHINE\System\CurrentControlSet\Services\ldap\Tracing\App1.exe

    so that no other users can trace App1.exe.
  5. Use a Trace Consumer such as Tracerpt.exe to review the information in the trace log:

    tracerpt.exe .\ldap.etl -o -report

 

 

Show: