Event Tracing in LDAP Applications (Windows)

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 #guid for ldap tracing provider -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 logfile to which events will be written. traceFlags should be one or more of the following values:

Flag Name	Flag Value	Flag Description
DEBUG_TRACE1	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 with DEBUG_SPEWSEARCH) Windows Vista/Windows Server 2008 and earlier: The flag name was DEBUG_TRACE1
DEBUG_TRACE2	0x00000002	Logs write requests and the parameters passed to them. It includes the operations: add, delete, modify, and extended. Windows Vista/Windows Server 2008 and earlier: The flag name was DEBUG_TRACE2
DEBUG_REFCNT	0x00000004	Logs reference counting data/operations for connections and requests.
DEBUG_HEAP	0x00000008	Logs all memory allocations and frees.
DEBUG_CACHE	0x00000010	Logs cache activity. Includes adds, removes, hits, misses, etc.
DEBUG_SSL	0x00000020	Logs SSL info and errors.
DEBUG_SPEWSEARCH	0x00000040	Logs all server responses to search requests. Includes attributes requested, as well as all data that was received. Windows Vista/Windows Server 2008 and earlier: Only available in debug builds.
DEBUG_SERVERDOWN	0x00000080	Logs server down/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. It includes reconnect attempts, failures, and related errors.
DEBUG_RECEIVEDATA	0x00000400	Logs info related to receiving messages from the server. Includes events such as: response received from server, waiting on response from server, etc.
DEBUG_BYTES_SENT	0x00000800	Logs all data sent by LDAP client to server. This is essentially packet logging, but it always logs unencrypted data. (So 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. Also includes things like message list cleared etc.
DEBUG_BER	0x00002000	Logs BER (Basic Encoding Rules) operations and errors. This includes problems with encoding, buffer size problems, etc.
DEBUG_OUTMEMORY	0x00004000	Logs failures to allocate memory. Generally logs any failure to compute the required memory as well. For example, overflow when computing required buffer size.
DEBUG_CONTROLS	0x00008000	Logs data related to controls. Includes inserting controls, problems with controls, mandatory controls on a connection, etc.
DEBUG_BYTES_RECEIVED	0x00010000	Logs all data received by LDAP client. This is essentially packet logging, but it always logs unencrypted data. (So 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/connectionless LDAP.
DEBUG_FILTER	0x00040000	Logs events and errors encountered when constructing a search filter. Note Only logs client-side events during filter construction. No responses from the server regarding a filter are included here.
DEBUG_BIND	0x00080000	Logs bind events and errors. Includes negotiation info, bind success, bind fail, etc.
DEBUG_NETWORK_ERRORS	0x00100000	Logs general network errors. Includes send and receive errors. Note If a connection is lost or the server cannot be reached, DEBUG_SERVERDOWN is the preferred tag.
DEBUG_SCRATCH	0x00200000	Logs general messages. This should be used for any messages that tend to generate a large amount of output. Examples are: end of message reached, server has not responded yet, etc. Also useful for generic messages . Windows Vista/Windows Server 2008 and earlier: The flag name was DEBUG_SCRATCH.
DEBUG_PARSE	0x00400000	Logs general message/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/errors.
DEBUG_INIT_TERM	0x04000000	Logs module initialization and cleanup. (DLL Main, etc.)
DEBUG_API_ERRORS	0x08000000	Supports logging improper use of the API. For example, 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/underflow errors.

You can combine flags by combining the appropriate bits in the traceFlags argument. For example, to specify the DEBUG_TRACE1 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.

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
After this command has started, DEBUG_BIND tracing messages will be written to .\ldap.etl. Execute App1.exe and reproduce the unexpected behavior.
Shut down the tracing session as follows:

tracelog.exe -stop ldaptrace
Delete the registry key
HKEY_LOCAL_MACHINE\System\CurrentControlSet\Services\ldap\Tracing\App1.exe
so that no other users can trace App1.exe.
Use a Trace Consumer such as Tracerpt.exe to review the information in the trace log:

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

Send comments about this topic to Microsoft

Build date: 7/7/2009