Event Tracing in LDAP Applications

Article
05/31/2018

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 name	Flag value	Flag 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.

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

Event Tracing in LDAP Applications

Example Scenario

Additional resources