Every external LDAP request is listed with an incremental connection number, in this case conn=11 or conn=28, starting at conn=0 immediately 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 the nsslapd-accesslog-level configuration 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=0 to identify the distinct operations being performed. In Code Example 5-1, we have op=0 for the bind operation request and result pair, then op=1 for the LDAP search request and result pair, and so on. Should you see op=-1 in 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:

0 = no authentication

128 = simple bind with user password

sasl = SASL bind using external authentication mechanism

The 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 number 0 means 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=97 for a result from a client bind operation.
  
  
• tag=100 indicates the actual entry for which you were searching.
  
  
• tag=101 for a result from a search operation.
  
  
• tag=103 for a result from a modify operation.
  
  
• tag=105 for a result from an add operation.
  
  
• tag=107 for a result from delete operation.
  
  
• tag=109 for a result from a moddn operation.
  
  
• tag=111 for a result from a compare operation.
  
  
• tag=115 indicates 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=120 for a result from an extended operation.

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. An etime value 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 the nsslapd-accesslog-level configuration attribute.

The LDAP request type indicates the type of LDAP request being issued by the LDAP client. Possible values are:

• SRCH = search
  
  
• MOD = modify
  
  
• DEL = delete
  
  
• ADD = add
  
  
• MODDN = moddn
  
  
• EXT = extended operation
  
  
• ABANDON = abandon operation

If the LDAP request resulted in sorting of entries, then you will see SORT serialno followed 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:

• RESULT = result
  
  
• ENTRY = entry
  
  
• REFERRAL = referral or search reference

The 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 when the nsslapd-idlistscanlimit 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.

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 ResponseInformation

where RequestInformation is of the form:

beforeCount:afterCount:index:contentCount

and ResponseInformation is 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:value

The 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 = 0
afterCount = 5
value = 0210

and the second part, 10:5397 (0), is the VLV response information:

targetPosition = 10
contentCount = 5397
(resultCode) = (0)

The entry scope= n defines the scope of the search performed, and n can have a value of 0, 1, or 2.

0 = base search

1 = one-level search

2 = subtree search

For more information about search scopes, see "Using ldapsearch" in Appendix B, "Finding Directory Entries," in the Netscape Directory Server Administrator's Guide.

An extended operation OID, in this case either EXT oid="2.16.840.1.113730.3.5.3" or EXT 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, 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, and

targetop=1 corresponds 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 ABANDON request being sent, then the log will read as follows:

[21/Apr/2001:11:39:52 -0700] conn=12 op=2 ABANDON targetop=NOTFOUND msgid=2

where 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 than the Netscape Directory Server Operation Number but identifies the same operation. The message ID is used in the context of an ABANDON operation and tells the user which client operation is being abandoned.

In Directory Server, logging for multi-stage binds is explicit. Each stage in the bind process is logged, and, where appropriate, the progress statement SASL bind in progress is included.

In logging a SASL bind, the sasl method is followed by the LDAP version number (see Version Number) and the SASL mechanism used, as shown below with the GSS-API mechanism.

[05/Aug/2004:12:57:14 -0700] conn=32 op=0 BIND dn="" method=sasl version=3 mech=GSSAPI

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.

Code Example 5-3    Access Log Extract with Entry Access and Referral Logging Level (Level 512)

The connection description, in this case conn=Internal, indicates that the connection is an internal connection. The operation number op=-1 also 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.

In Code Example 5-4, both access logging level 512 and 4 are enabled, which results in both internal access operations and entry access and referrals being logged.

Code Example 5-4    Access Log Extract with Internal Access Operation, Entry Access and Referral Logging Levels (Levels 4+512)