cn=Directory Manager

cn=Directory Manager
All about Directory Server

All | Personal | Sun

« Previous day (Jul 19, 2006) | Main | Next day (Jul 20, 2006) »

Thursday July 20, 2006

The Directory Server Access Log Format

The Directory Server access log can be one of the most useful tools for understanding client behavior and debugging problems when things aren't working as expected. There's a lot of information that can show up in the log, and it may not be obvious in all cases what all of the information means so I'll give it a quick summary here.

Common Log Elements

All access log file lines have a few common elements:

{timestamp} -- The time that the message was logged, including the date, time, and offset from GMT.
conn -- The connection ID for the connection that triggered the log message. All log elements for actions associated with a given client connection will have the same connection ID. If you see a connection ID of -1, then it indicates that the associated message is associated with an internal operation and was not requested by an external client.
op -- The operation ID for the client operation associated with the log message. This can be used in conjunction with the connection ID to identify operations for a given client (the response log message for an operation will have the same conn and op values as the corresponding request log message). If you see an operation ID of -1, then it indicates that the log message was not associated with an LDAP request from the client but rather was some other notable event like establishing or terminating the connection.
msgId -- The message ID from the LDAP message that the client used in the request to the server. This can be useful in helping to debug the protocol-level communication with the client. As with the operation ID, a message ID of -1 indicates that the log message is not associated with a protocol operation requested by the client but some other event.

Connection Establishment

When a new connection is established, you'll see a line with the following elements:

fd -- The file descriptor number for the socket associated with the client connection.
slot -- The slot in the internal connection table for the client connection structure. This is usually the same as the file descriptor number.
{protocol} -- The protocol that the client is using to communicate with the server. This could be LDAP, LDAPS, or HTTP (for DSML).
connection from {address} -- The IP address of the client (as seen by the server, so this could be the address of an intermediate system like a proxy)
to {address} -- The IP address on the server system to which the connection was established, which can be useful if the server is multi-homed

If it's an SSL=based connection, then you'll also see a line indicating the cipher that was used, like "SSL 128-bit RC4". If the client sent its own certificate to the server, then the subject of that certificate will also be included.

Connection Closure

When a connection is closed, you'll generally see a couple of lines. The first one indicates that the connection is going to be closed and the second that it has been closed. The first of these two lines also contains a closure code that can help indicate why the connection was closed. These closure codes include:

A1 -- The client aborted the connection (i.e., closed without sending an unbind). This is generally only seen on Windows systems, as B1 usually means this on UNIX systems.
B1 -- On UNIX systems, this virtually always means that the client closed the connection without sending an unbind request. It could also mean that the client sent a malformed request to the server.
B2 -- The client sent a request that was too large (i.e., exceeded the max BER size).
B4 -- The server got an error when it was trying to send data to the cient.
T1 -- The client connection was closed because it remained idle for too long (i.e., the idletimeout was reached).
T2 -- The server closed the client connection because the client started to send a request but took to long to send the rest of it, or because the server started to send a response to the client but the write blocked for too long (i.e., the ioblocktimeout was reached).
P1 -- The client connection was closed by a plugin.
U1 -- The client connection was closed when the client sent an unbind request.

Response Lines

Whenever the server processes a request from the client, the server will generally log two lines: one when it starts to process the request, and a second when that processing has completed and the server has sent the response (unless there isn't a response, like with an unbind or abandon). The request line may vary based on the type of operation, but the response line will always have the following elements:

err -- The LDAP result code for the operation. A result code of zero generally indicates that the operation was successful, while nonzero indicates an error (although there are a few exceptions, like 5=compare false, 6=compare true, or 14=SASL bind in progress).
tag -- The decimal value of the BER type tag from the protocol op of the response message. They include: 97=bind, 101=search, 103=modify, 105=add, 107=delete, 109=modify DN, 111=compare, 120=extended operation.
nentries -- The number of entries returned to the client. This will only ever be nonzero for a search, but it's included on all response lines.
etime -- The length of time required to process the request, in seconds (although it's possible to make it sub-second by changing nsslapd-accesslog-level to 131328 in cn=config).

Bind Requests

The following elements may be logged as part of a bind request:

dn -- The DN contained in the bind request. Note that this may be empty for anonymous binds, but it will also often be empty for SASL binds since the identity of the user is defined in another manner.
method -- The authentication method. It will be "128" for a simple bind, or "sasl" for a SASL bind.
version -- The LDAP protocol version. It will be 3 for LDAPv3 or 2 for LDAPv2.
mech -- The SASL mechanism used (only present in SASL binds).

Note that the response line for a bind operation will also contain an additional field "dn", which is the identity of the user that actually authenticated. This can be useful for cases in which the client used SASL authentication so the bind DN isn't visible in the request line, and it's also a good way to double-check the authentication performed since there can be cases in which a successful bind can be authenticated as a user different from the one specified in the DN field of the bind request.

Search Requests

The following elements may be logged as part of a search request:

base -- The base DN for the search request.
scope -- The scope for the search request. A value of 0 indicates that it's a base-level search, 1 means single-level, and 2 means whole subtree.
filter -- The string representation of the filter from the search request.
attrs -- The list of attributes requested by the client, or "ALL" if the client didn't request any specific attributes.

Add, Delete, and Modify Requests

Add, delete, and modify requests all have the same format for the request log messages. It contains only the DN of the entry being added, deleted, or modified.

Modify DN Requests

The following elements may be logged as part of a modify DN request:

dn -- The original DN of the entry being moved/renamed.
newrdn -- The new RDN for the entry.
newsuperior -- The new superior DN for the entry, or "(null)" if the newSuperior element was not included in the request.

Compare Requests

The following elements may be logged as part of a compare request:

dn -- The DN of the entry targeted by the compare request.
attr -- The attribute for which the comparison is being made.

Extended Operation Requests

Extended operation requests have only a single element in the request line, which is the OID for the extended operation.

Posted by cn_equals_directory_manager ( Jul 20 2006, 08:05:27 AM CDT ) Permalink Comments [3]