|
Configuration, Command, and File Reference Netscape Directory Server |
|
||
|
|
Chapter 5 Access Log and Connection Code Reference
Netscape Directory Server (Directory Server) provides you with logs to help you monitor directory activity. Monitoring allows you to quickly detect and remedy failures and where done proactively, anticipate and resolve potential problems before they result in failure or poor performance. To monitor your directory effectively, you need to understand the structure and content of your logs.
Note that this chapter does not provide an exhaustive list of error messages. However, the information presented in this chapter will serve as a a good starting point for common problems. This chapter includes the following sections:
The Directory Server access log contains detailed information about client connections to the directory. A connection is a sequence of requests from the same client with the following structure:
- Connection record which gives the connection index and the IP address of the client
- Bind record
- Bind result record
- Sequence of operation request/operation result pairs of records (or individual records in the case of connection, closed and abandon records)
- Unbind record
- Closed record
Every line begins with a timestamp - [21/Apr/2001:11:39:51 -0700]- the format of which may vary depending on which platform you are using, where
-0700indicates the time difference in relation to GMT. Apart from the connection, closed and abandon records, which appear individually, all records appear in pairs, consisting of a request for service record followed by a result record. These two records frequently appear on adjacent lines but this is not always the case.This section presents the different levels of access logging available with Directory Server, then describes the default access logging content and ends with a description of the additional access logging level content. This section is divided into the following parts:
- Access Logging Levels
- Default Access Logging Content
- Access Log Content for Additional Access Logging Levels
Directory Server provides a script, which can analyze access logs to extract usage statistics and count the occurrences of significant events. For details about this script, see "logconv.pl (Log converter)".
Different levels of access log logging exist and by changing the value of the
nsslapd-accesslog-levelconfiguration attribute (see "nsslapd-accesslog-level"), you can select the exact type of logging you require. The default level of logging is level 256, which logs access to an entry but you can choose from the following logging levels, combining more than one level to suit your needs:
4= Logging for internal access operations
256= Logging for access to an entry
512= Logging for access to an entry and referrals
131072= Precise timing of operation duration. This gives microsecond resolution for the Elapsed Time item in the access log.For example, if you want to log internal access operations, entry access, and referrals, you would insert a value of 516 (512+4) in the
nsslapd-accesslog-levelconfiguration attribute. For further information on other access log configuration attributes, see "Core Server Configuration Attributes Reference"."Default Access Logging Content
This section describes the access log content in detail based on the default access logging level extract in Code Example 5-1.
Every external LDAP request is listed with an incremental connection number, in this case
conn=11orconn=28, starting atconn=0immediately after server startup. Internal LDAP requests are not recorded in the access log by default. To activate the logging of internal access operations, specify access logging level 4 on thensslapd-accesslog-levelconfiguration attribute (see "nsslapd-accesslog-level").Every connection from an external LDAP client to Directory Server requires a file descriptor, or socket descriptor from the operating system in this case fd=608. fd=608 indicates that it was file descriptor number 608 out of the total pool of available file descriptors which was used.
The slot number, in this case
slot=608, is a legacy part of the access log which has the same meaning as file descriptor. Ignore this part of the access log.To process a given LDAP request, Directory Server will perform the required series of operations. For a given connection, all operation request and operation result pairs are given incremental operation numbers beginning with
op=0to identify the distinct operations being performed. In Code Example 5-1 we haveop=0for the bind operation request and result pair, thenop=1for the LDAP search request and result pair, and so on. Should you seeop=-1in the access log it generally means that the LDAP request for this connection was not issued by an external LDAP client, but instead initiated internally.The method number, in this case method=128, indicates which LDAPv3 bind method was used by the client. There are three possible bind method values:
128= simple bind with user password
sasl= SASL bind using external authentication mechanismThe version number, in this case,
version=3, indicates the LDAP version number (either LDAPv2 or LDAPv3) that the LDAP client used to communicate with the LDAP server.The error number, in this case
err=0, provides the LDAP result code returned from the LDAP operation performed. The LDAP error number0means that the operation was successful. For a more comprehensive list of LDAP result codes see "LDAP Result Codes".The tag number, in this case
tag=97, indicates the type of result returned, which is almost always a reflection of the type of operation performed. The tags used are the BER tags from the LDAP protocol. Commonly used tags include:
tag=97for a result from a client bind operation
tag=100indicates the actual entry for which you were searching
tag=101for a result from a search operation
tag=103for a result from a modify operation
tag=105for a result from an add operation
tag=107for a result from delete operation
tag=109for a result from a moddn operation
tag=111for a result from a compare operation
tag=115indicates a search reference when the entry you perform your search on holds a referral to the entry you require. Search references are expressed in terms of a referral.
tag=120for a result from an extended operation
tag=100andtag=115are not result tags as such and so it is unlikely that you will see them in your access log.
The number of entries, in this case
nentries=0, indicates the number of entries that were found matching the LDAP client's request.Elapsed time, in this case
etime=1000, indicates the amount of time (in seconds) that it took the directory server to perform the LDAP operation. Anetimevalue of 0 means that the operation actually took milliseconds to perform. If you want to have microsecond resolution for this item in the access log, enter a value of 131328 (256+131072) in thensslapd-accesslog-levelconfiguration attribute.The LDAP request type indicates the type of LDAP request being issued by the LDAP client. Possible values are:
Note that if the LDAP request resulted in sorting of entries, then you will see
SORT serialnofollowed by the number of candidate entries that were sorted. See the bold text in this example:[04/May/2002:15:51:46 -0700] conn=114 op=68
SORT serialno (1)The number enclosed in parentheses specifies the number of candidate entries that were sorted, which, in this case is 1.
The LDAP response type indicates the LDAP response being issued by the LDAP client. Possible values are:
REFERRAL= referral or search referenceThe unindexed search indicator,
notes=U, indicates that the search performed was unindexed, which means that the database itself had to be directly searched instead of the index file. Unindexed searches occur either when the All IDs Threshold was reached within the index file used for the search, when no index file existed or when the index file was not configured in the way required by the search.
An unindexed search indicator is often accompanied by a large
etimevalue, as unindexed searches are generally more time consuming.
When a search involves virtual list views (VLVs), appropriate entries are logged in the access log file. Similar to the other entries, VLV-specific entries show the request and response information side by side, like this:
VLV RequestInformation ResponseInformationwhere
RequestInformationis of the form:beforeCount:afterCount:index:contentCountand
ResponseInformationis of the form:targetPosition:contentCount (resultCode)If the client uses a position-by-value VLV request, the format for the first part, the request information, would be:
beforeCount:afterCount:valueThe example below shows VLV-specific entries in bold:
[07/May/2002:11:43:29 -0700] conn=877 op=8530 SRCH base="(ou=People)" scope=2 filter="(uid=*)"
[07/May/2002:11:43:29 -0700] conn=877 op=8530 SORT uid
[07/May/2002:11:43:29 -0700] conn=877 op=8530
VLV 0:5:0210 10:5397 (0)[07/May/2002:11:43:29 -0700] conn=877 op=8530 RESULT err=0 tag=101 nentries=1 etime=0
In the above example, the first part,
0:5:0210, is the VLV request information:
beforeCount= 0afterCount= 5value= 0210
and the second part,
10:5397 (0), is the VLV response information:
targetPosition= 10contentCount= 5397(resultCode)= (0)
The entry
scope=ndefines the scope of the search performed, andncan have a value of 0, 1, or 2.For more information about search scopes, see section "Using ldapsearch" in Appendix B, "Finding Directory Entries" of Netscape Directory Server Administrator's Guide.
An extended operation OID, in this case either
EXT oid="2.16.840.1.113730.3.5.3"orEXT oid="2.16.840.1.113730.3.5.5", provides the OID of the extended operation being performed. Table 5-1 provides the list of LDAPv3 extended operations and their OIDs supported in Directory Server.
Table 5-1 LDAPv3 Extended Operations supported by Directory Server
The change sequence number, in this case
csn=3b4c8cfb000000030000, is the replication change sequence number, thus indicating that replication is enabled on this particular naming context.The abandon message, in this case, [
21/Apr/2001:11:39:52 -0700]conn=12 op=2 ABANDON targetop=1 msgid=2 nentries=0 etime=0,indicates that an operation has been aborted, where nentries=0 indicates the number of entries sent before the operation was aborted, etime=0 value indicates how much time (in seconds) had elapsed, andtargetop=1corresponds to an operation value from a previously initiated operation (that appears earlier in the access log).There are two possible log ABANDON messages depending on whether the message ID succeeds in locating which operation was to be aborted or not. If the message ID succeeds in locating the operation (the targetop) then the log will read as above. However, if the message ID does not succeed in locating the operation or if the operation had already finished prior to the
ABANDONrequest being sent, then the log will read as follows:[
21/Apr/2001:11:39:52 -0700] conn=12 op=2 ABANDON targetop=NOTFOUND msgid=2where targetop=NOTFOUND indicates the operation to be aborted was either an unknown operation or already complete.
The message ID, in this case
msgid=2, is the LDAP operation identifier, as generated by the LDAP SDK client. The message ID may have a different value to the Netscape Directory Server Operation Number, but identifies the same operation. The message ID is used in the context of anABANDONoperation and tells the user which client operation is being abandoned.
Directory Server 6.x logging for multi-stage binds is now more explicit. Each stage in the bind process is now logged and where appropriate the progress statement SASL bind in progress is included.
Access Log Content for Additional Access Logging Levels
This section presents the additional access logging levels available in the Directory Server access log. In Code Example 5-2 access logging level 4 is enabled which logs internal operations.
Access log level 4 enables logging for internal operations which log the following items in addition to the details of the search being performed, including search base, scope, filter, and requested search attributes.
In Code Example 5-3, access logging level 512 is enabled which logs access to entries and referrals. In this extract, 6 entries and 1 referral are returned in response to the search request, which is shown in bold.
The connection description, in this case
conn=Internal,indicates that the connection is an internal connection. The operation numberop=-1also indicates that the operation was initiated internally.The options description, in this case
options=persistent, indicates that a persistent search is being performed. Persistent searches can be used as a form of monitoring and configured to return changes to given configurations as and when changes occur.
Directory Server access log now distinguishes between persistent and regular searches, which was not the case for previous Directory Server releases.
In Code Example 5-4 both access logging level 512 and 4 are enabled, which results in both internal access operations, as well as entry access and referrals being logged.
A connection code is a code which is added to the
closedlog message to provide additional information related to the connection closure. Common connection codes include:A1 = Client aborts the connection.
B1 = Corrupt BER tag encountered.
If BER tags, which encapsulate data being sent over the wire, are corrupt when they are received, a
B1connection code is logged to the access log. BER tags can be corrupted due to physical layer network problems or bad LDAP client operations, such as an LDAP client aborting before receiving all request results.B2 = BER tag is longer than the
nsslapd-maxbersizeattribute value. For further information about this configuration attribute see "nsslapd-maxbersize (Maximum Message Size)".B3 = Corrupt BER tag encountered
B4 = Server failed to flush data response back to client
P2 = Closed or corrupt connection has been detected.
T1 = Client does not receive a result within the specified idletimeout period
T2 = Server closed connection after ioblocktimeout period was exceeded
U1 = Connection closed by server after client sends an UNBIND request. The server will always close the connection when it sees an UNBIND request.
LDAP has a set of result codes that it is useful to be familiar with.
© 2001 Sun Microsystems, Inc. Portions copyright 1999, 2002 Netscape Communications Corporation. All rights reserved.
Last Updated August 16, 2002