Chapter 7. Log File Reference Red Hat Directory Server (Directory Server) provides logs to help monitor directory activity. Monitoring helps quickly detecting and remedying failures and, where done proactively, anticipating and resolving potential problems before they result in failure or poor performance. Part of monitoring the directory effectively is understanding the structure and content of the log files. This chapter does not provide an exhaustive list of log messages. However, the information presented in this chapter serves as a good starting point for common problems and for better understanding the information in the access, error, and audit logs. Logs are kept per Directory Server instances and are located in the /var/log/dirsrv/slapd- instance directory. 7.1. Access Log Reference 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 provides the connection index and the IP address of the client Bind record Bind result record Sequence of operation request and operation result pairs of records, or individual records in the case of connection, closed, and abandon records Unbind record Closed record The following is an example access log entry: Apart from 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: The RESULT message contains the following performance-related entries:; wtime : The amount of time the operation was waiting in the work queue before a worker thread picked up the operation optime : The amount of time it took for the actual operation to perform the task etime : The elapsed time, which covers the time the operation was received by the server to when the server sent back the result to the client Note The wtime and optime values provide useful information about how the server handles load and processes operations. Due to the timing of when Directory Server gathers these statistics, the sum of the wtime and optime values are slightly greater than the etime value. However, this very small difference is negligible. The access logs have different levels of logging, set in the nsslapd-accesslog-level attribute. The following sections provide an overview of the default access logging content, log levels, and the content logged at different logging levels: Section 7.1.1, "Access Logging Levels" Section 7.1.2, "Default Access Logging Content" Section 7.1.3, "Access Log Content for Additional Access Logging Levels" Note that you cannot change the format of the access log. 7.1.1. Access Logging Levels Different levels of access logging generate different amounts of detail and record different kinds of operations. The log level is set in the instance's Section 3.1.1.2, "nsslapd-accesslog-level (Access Log Level)" configuration attribute. The default level of logging is level 256, which logs access to an entry, but there are four different log levels available: 0 = No access logging. 4 = Logging for internal access operations. 256 = Logging for access to an entry. 512 = Logging for access to an entry and referrals. This levels are additive, so to enable several different kinds of logging, add the values of those levels together. For example, to log internal access operations, entry access, and referrals, set the value of nsslapd-accesslog-level to 516 ( 512 + 4 ). 7.1.2. Default Access Logging Content This section describes the access log content in detail based on the default access logging level extract shown below. Example 7.1. Example Access Log Connection Number Every external LDAP request is listed with an incremental connection number, in this case conn=11 , 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 Section 3.1.1.2, "nsslapd-accesslog-level (Access Log Level)" configuration attribute. File Descriptor 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. Slot Number 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. Operation Number 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 Section 7.1.2, "Default Access Logging Content" , 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. The entry op=-1 in the access log generally means that the LDAP request for this connection was not issued by an external LDAP client but, instead, initiated internally. Method Type 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 for authentication 128 for simple bind with user password sasl for SASL bind using external authentication mechanism Version Number 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. Error Number 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 Section 7.4, "LDAP Result Codes" . Tag Number 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. Table 7.1. Commonly-Used Tags Tag Description tag=97 Result from a client bind operation. tag=100 The actual entry being searched for. tag=101 Result from a search operation. tag=103 Result from a modify operation. tag=105 Result from an add operation. tag=107 Result from a delete operation. tag=109 Result from a moddn operation. tag=111 Result from a compare operation. tag=115 Search reference when the entry on which the search was performed holds a referral to the required entry. Search references are expressed in terms of a referral. tag=120 Result from an extended operation. tag=121 Result from an intermediate operation. Note tag=100 and tag=115 are not result tags as such, and so it is unlikely that they will be recorded in the access log. Number of Entries nentries shows the number of entries, in this case nentries=0 , that were found matching the LDAP client's request. Elapsed Time etime shows the elapsed time, in this case etime=3 , or 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 0 nanoseconds to perform. LDAP Request Type The LDAP request type indicates the type of LDAP request being issued by the LDAP client. Possible values are: SRCH for search MOD for modify DEL for delete ADD for add MODDN for moddn EXT for extended operation ABANDON for abandon operation If the LDAP request resulted in sorting of entries, then the message SORT serialno will be recorded in the log, followed by the number of candidate entries that were sorted. For example: The number enclosed in parentheses specifies the number of candidate entries that were sorted, which in this case is 1 . LDAP Response Type The LDAP response type indicates the LDAP response being issued by the LDAP client. There are three possible values: RESULT ENTRY REFERRAL , an LDAP referral or search reference Search Indicators Directory Server provides additional information on searches in the notes field of log entries. For example: The following search indicators exist: Paged Search Indicator: notes=P LDAP clients with limited resources can control the rate at which an LDAP server returns the results of a search operation. When the search performed used the LDAP control extension for simple paging of search results, Directory Server logs the notes=P paged search indicator. This indicator is informational and no further actions are required. For more details, see RFC 2696 . Unindexed Search Indicators: notes=A and notes=U When attributes are not indexed, Directory Server must search them in the database directly. This procedure is more resource-intensive than searching the index file. The following unindexed search indicators can be logged: notes=A All candidate attributes in the filter were unindexed and a full table scan was required. This can exceed the value set in the nsslapd-lookthroughlimit parameter. notes=U This state is set in the following situations: At least one of the search terms is unindexed. The limit set in the nsslapd-idlistscanlimit parameter was reached during the search operation. For details, see Section 4.4.1.9, "nsslapd-idlistscanlimit" . Unindexed searches occur in the following scenarios: The nsslapd-idlistscanlimit parameter's value was reached within the index file used for the search. No index file existed. The index file was not configured in the way required by the search. To optimize future searches, add frequently searched unindexed attributes to the index. For details, see the corresponding section in the Directory Server Administration Guide . Note An unindexed search indicator is often accompanied by a large etime value, as unindexed searches are generally more time consuming. Beside a single value, the notes field can have the following value combinations: notes=P,A and notes=U,P . VLV-Related Entries 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: RequestInformation has the following form: If the client uses a position-by-value VLV request, the format for the first part, the request information would be beforeCount: afterCount: value . ResponseInformation has the following form: The example below highlights the VLV-specific entries: In the above example, the first part, 0:5:0210 , is the VLV request information: The beforeCount is 0 . The afterCount is 5 . The value is 0210 . The second part, 10:5397 (0) , is the VLV response information: The targetPosition is 10 . The contentCount is 5397 . The (resultCode) is (0) . Search Scope The entry scope=n defines the scope of the search performed, and n can have a value of 0 , 1 , or 2 . 0 for base search 1 for one-level search 2 for subtree search Extended Operation OID An extended operation OID, such as EXT oid="2.16.840.1.113730.3.5.3" or EXT oid="2.16.840.1.113730.3.5.5" in Example 7.1, "Example Access Log" , provides the OID of the extended operation being performed. Table 7.2, "LDAPv3 Extended Operations Supported by Directory Server" provides a partial list of LDAPv3 extended operations and their OIDs supported in Directory Server. Table 7.2. LDAPv3 Extended Operations Supported by Directory Server Extended Operation Name Description OID Directory Server Start Replication Request Sent by a replication initiator to indicate that a replication session is requested. 2.16.840.1.113730.3.5.3 Directory Server Replication Response Sent by a replication responder in response to a Start Replication Request Extended Operation or an End Replication Request Extended Operation. 2.16.840.1.113730.3.5.4 Directory Server End Replication Request Sent to indicate that a replication session is to be terminated. 2.16.840.1.113730.3.5.5 Directory Server Replication Entry Request Carries an entry, along with its state information ( csn and UniqueIdentifier ) and is used to perform a replica initialization. 2.16.840.1.113730.3.5.6 Directory Server Bulk Import Start Sent by the client to request a bulk import together with the suffix being imported to and sent by the server to indicate that the bulk import may begin. 2.16.840.1.113730.3.5.7 Directory Server Bulk Import Finished Sent by the client to signal the end of a bulk import and sent by the server to acknowledge it. 2.16.840.1.113730.3.5.8 Change Sequence Number 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. Abandon Message The abandon message indicates that an operation has been aborted. 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. 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: targetop=NOTFOUND indicates the operation to be aborted was either an unknown operation or already complete. Message ID 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 operation number but identifies the same operation. The message ID is used with an ABANDON operation and tells the user which client operation is being abandoned. Note The Directory Server operation number starts counting at 0, and, in the majority of LDAP SDK/client implementations, the message ID number starts counting at 1, which explains why the message ID is frequently equal to the Directory Server operation number plus 1. SASL Multi-Stage Bind Logging In Directory Server, logging for multi-stage binds is explicit. Each stage in the bind process is logged. The error codes for these SASL connections are really return codes. In Example 7.1, "Example Access Log" , the SASL bind is currently in progress so it has a return code of err=14 , meaning the connection is still open, and there is a corresponding progress statement, SASL bind in progress . In logging a SASL bind, the sasl method is followed by the LDAP Version Number and the SASL mechanism used, as shown below with the GSS-API mechanism. Note The authenticated DN (the DN used for access control decisions) is now logged in the BIND result line as opposed to the bind request line, as was previously the case: For SASL binds, the DN value displayed in the bind request line is not used by the server and, as a consequence, is not relevant. However, given that the authenticated DN is the DN which, for SASL binds, must be used for audit purposes, it is essential that this be clearly logged. Having this authenticated DN logged in the bind result line avoids any confusion as to which DN is which. 7.1.3. Access Log Content for Additional Access Logging Levels This section presents the additional access logging levels available in the Directory Server access log. In Example 7.2, "Access Log Extract with Internal Access Operations Level (Level 4)" , access logging level 4 , which logs internal operations, is enabled. Example 7.2. Access Log Extract with Internal Access Operations Level (Level 4) Access log level 4 enables logging for internal operations, which log search base, scope, filter, and requested search attributes, in addition to the details of the search being performed. In the following example, access logging level 768 is enabled (512 + 256), which logs access to entries and referrals. In this extract, six entries and one referral are returned in response to the search request, which is shown on the first line. Connection Description 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. Options Description The options description ( options=persistent ) indicates that a persistent search is being performed, as distinguished from a regular search operation. Persistent searches can be used as a form of monitoring and configured to return changes to given configurations as changes occur. Both log levels 512 and 4 are enabled for this example, so both internal access operations and entry access and referrals being logged. 7.1.4. Common Connection Codes A connection code is a code that is added to the closed log message to provide additional information related to the connection closure. Table 7.3. Common Connection Codes Connection Code Description 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 B1 connection 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-maxbersize attribute value. For further information about this configuration attribute, see Section 3.1.1.118, "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. For further information about this configuration attribute, see Section 3.1.1.97, "nsslapd-idletimeout (Default Idle Timeout)" . T2 Server closed connection after ioblocktimeout period was exceeded. For further information about this configuration attribute, see Section 3.1.1.100, "nsslapd-ioblocktimeout (IO Block Time Out)" . U1 Connection closed by server after client sends an unbind request. The server will always close the connection when it sees an unbind request. 7.2. Error Log Reference The Directory Server error log records messages for Directory Server transactions and operations. These may be error messages for failed operations, but it also contains general information about the processes of Directory Server and LDAP tasks, such as server startup messages, logins and searches of the directory, and connection information. 7.2.1. Error Log Logging Levels The error log can record different amounts of detail for operations, as well as different kinds of information depending on the type of error logging enabled. The logging level is set in the Section 3.1.1.79, "nsslapd-errorlog-level (Error Log Level)" configuration attribute. The default log level is 16384 , which included critical error messages and standard logged messages, like LDAP results codes and startup messages. As with access logging, error logging levels are additive. To enable both replication logging ( 8192 ) and plug-in logging ( 65536 ), set the log level to 73728 ( 8192 + 65536 ). Note Enabling high levels of debug logging can significantly erode server performance. Debug log levels, such as replication ( 8192 ) should only be enabled for troubleshooting, not for daily operations. Table 7.4. Error Log Levels Setting Console Name Description 1 Trace function calls Logs a message when the server enters and exits a function. 2 Packeting handlings Logs debug information for packets processed by the server. 4 Heavy trace output Logs when the server enters and exits a function, with additional debugging messages. 8 Connection management Logs the current connection status, including the connection methods used for a SASL bind. 16 Packets sent/received Print out the numbers of packets sent and received by the server. 32 Search filter processing Logs all of the functions called by a search operation. 64 Config file processing Prints any .conf configuration files used with the server, line by line, when the server is started. By default, only slapd-collations.conf is available and processed. 128 Access control list processing Provides very detailed access control list processing information. 2048 Log entry parsing Logs schema parsing debugging information. 4096 Housekeeping Housekeeping thread debugging. 8192 Replication Logs detailed information about every replication-related operation, including updates and errors, which is important for debugging replication problems. 16384 Default Default level of logging used for critical errors and other messages that are always written to the error log, such as server startup messages. Messages at this level are always included in the error log, regardless of the log level setting. 32768 Entry cache Database entry cache debugging. 65536 Plug-ins Writes an entry to the log file when a server plug-in calls slapi-log-error , so this is used for server plug-in debugging. 262144 Access control summary Summarizes information about access to the server, much less verbose than level 128 . This value is recommended for use when a summary of access control processing is needed. Use 128 for very detailed processing messages. 7.2.2. Error Log Content The format of the error log differs compared from that of the access log: Log entries written by the server Entries that the server writes to the file, use the following format: For example: Log entries written by plug-ins Entries that plug-ins write to the file, use the following format: For example: Error log entries contain the following columns: Time stamp: The format can differ depending on your local settings. If high-resolution time stamps are enabled in the nsslapd-logging-hr-timestamps-enabled attribute in the cn=config entry (default), the time stamp is exact to the nanosecond. Severity level: The following severity levels are used: EMERG : This level is logged when the server fails to start. ALERT : The server is in a critical state and possible action must be taken. CRIT : Severe error. ERR : General error. WARNING : A warning message, that is not necessarily an error. NOTICE : A normal, but significant condition occurred. For example, this is logged for expected behavior. INFO : Informational messages, such as startup, shutdown, import, export, backup, restore. DEBUG : Debug-level messages. This level is also used by default when using a verbose logging level, such as Trace function calls (1), Access control list processing (128), and Replication (8192). For a list of error log levels, see Table 7.4, "Error Log Levels" . You can use the severity levels to filter your log entries. For example, to display only log entries using the ERR severity: Plug-in name: If a plug-in logged the entry, this column displays the name of the plug-in. If the server logged the entry, this column does not appear. Function name: Functions that the operation or the plug-in called. Message: The output that the operation or plug-in returned. This message contains additional information, such as LDAP error codes and connection information. 7.2.3. Error Log Content for Other Log Levels The different log levels return not only different levels of detail, but also information about different types of server operations. Some of these are summarized here, but there are many more combinations of logging levels possible. Replication logging is one of the most important diagnostic levels to implement. This logging level records all operations related to replication and Windows synchronization, including processing modifications on a supplier and writing them to the changelog, sending updates, and changing replication agreements. Whenever a replication update is prepared or sent, the error log identifies the replication or synchronization agreement being specified, the consumer host and port, and the current replication task. For example: {replicageneration} means that the new information is being sent, and 4949df6e000000010000 is the change sequence number of the entry being replicated. Example 7.3, "Replication Error Log Entry" shows the complete process of sending a single entry to a consumer, from adding the entry to the changelog to releasing the consumer after replication is complete. Example 7.3. Replication Error Log Entry Plug-in logging records every the name of the plug-in and all of the functions called by the plug-in. This has a simple format: The information returned can be hundreds of lines long as every step is processed. The precise information recorded depends on the plug-in itself. For example, the ACL Plug-in includes a connection and operation number, as shown in Example 7.4, "Example ACL Plug-in Error Log Entry with Plug-in Logging" . Example 7.4. Example ACL Plug-in Error Log Entry with Plug-in Logging Note Example 7.4, "Example ACL Plug-in Error Log Entry with Plug-in Logging" shows both plug-in logging and search filter processing (log level 65696). Many other kinds of logging have similar output to the plug-in logging level, only for different kinds of internal operations. Heavy trace output ( 4 ), access control list processing ( 128 ), schema parsing ( 2048 ), and housekeeping ( 4096 ) all record the functions called by the different operations being performed. In this case, the difference is not in the format of what is being recorded, but what operations it is being recorded for. The configuration file processing goes through any .conf file, printing every line, whenever the server starts up. This can be used to debug any problems with files outside of the server's normal configuration. By default, only slapd-collations.conf file, which contains configurations for international language sets, is available. Example 7.5. Config File Processing Log Entry There are two levels of ACI logging, one for debug information and one for summary. Both of these ACI logging levels records some extra information that is not included with other types of plug-ins or error logging, including Connection Number and Operation Number information. Show the name of the plug-in, the bind DN of the user, the operation performed or attempted, and the ACI which was applied. The debug level shows the series of functions called in the course of the bind and any other operations, as well. Example 7.6, "Access Control Summary Logging" shows the summary access control log entry. Example 7.6. Access Control Summary Logging 7.3. Audit Log Reference The audit log records changes made to the server instance. Unlike the error and access log, the audit log does not record access to the server instance, so searches against the database are not logged. The audit log is formatted differently than the access and error logs and is like a time-stamped LDIF file. The operations recorded in the audit log are formatted as LDIF statements: LDIF files and formats are described in more detail in the "LDAP Data Interchange Format" appendix of the Administration Guide . Several different kinds of audit entries are shown in Example 7.7, "Audit Log Content" . Example 7.7. Audit Log Content Note that you cannot change to format or set a log level for the audit log. 7.4. LDAP Result Codes Directory Server uses the following LDAP result codes: Table 7.5. LDAP Result Codes Decimal Values Hex Values Constants 0 0x00 LDAP_SUCCESS 1 0x01 LDAP_OPERATIONS_ERROR 2 0x02 LDAP_PROTOCOL_ERROR 3 0x03 LDAP_TIMELIMIT_EXCEEDED 4 0x04 LDAP_SIZELIMIT_EXCEEDED 5 0x05 LDAP_COMPARE_FALSE 6 0x06 LDAP_COMPARE_TRUE 7 0x07 LDAP_AUTH_METHOD_NOT_SUPPORTED LDAP_STRONG_AUTH_NOT_SUPPORTED 8 0x08 LDAP_STRONG_AUTH_REQUIRED 9 0x09 LDAP_PARTIAL_RESULTS 10 0x0a LDAP_REFERRAL [a] 11 0x0b LDAP_ADMINLIMIT_EXCEEDED 12 0x0c LDAP_UNAVAILABLE_CRITICAL_EXTENSION 13 0x0d LDAP_CONFIDENTIALITY_REQUIRED 14 0x0e LDAP_SASL_BIND_IN_PROGRESS 16 0x10 LDAP_NO_SUCH_ATTRIBUTE 17 0x11 LDAP_UNDEFINED_TYPE 18 0x12 LDAP_INAPPROPRIATE_MATCHING 19 0x13 LDAP_CONSTRAINT_VIOLATION 20 0x14 LDAP_TYPE_OR_VALUE_EXISTS 21 0x15 LDAP_INVALID_SYNTAX 32 0x20 LDAP_NO_SUCH_OBJECT 33 0x21 LDAP_ALIAS_PROBLEM 34 0x22 LDAP_INVALID_DN_SYNTAX 35 0x23 LDAP_IS_LEAF [b] 36 0x24 LDAP_ALIAS_DEREF_PROBLEM 48 0x30 LDAP_INAPPROPRIATE_AUTH 49 0x31 LDAP_INVALID_CREDENTIALS 50 0x32 LDAP_INSUFFICIENT_ACCESS 51 0x33 LDAP_BUSY 52 0x34 LDAP_UNAVAILABLE 53 0x35 LDAP_UNWILLING_TO_PERFORM 54 0x36 LDAP_LOOP_DETECT 60 0x3c LDAP_SORT_CONTROL_MISSING 61 0x3d LDAP_INDEX_RANGE_ERROR 64 0x40 LDAP_NAMING_VIOLATION 65 0x41 LDAP_OBJECT_CLASS_VIOLATION 66 0x42 LDAP_NOT_ALLOWED_ON_NONLEAF 67 0x43 LDAP_NOT_ALLOWED_ON_RDN 68 0x44 LDAP_ALREADY_EXISTS 69 0x45 LDAP_NO_OBJECT_CLASS_MODS 70 0x46 LDAP_RESULTS_TOO_LARGE [c] 71 0x47 LDAP_AFFECTS_MULTIPLE_DSAS 76 0x4C LDAP_VIRTUAL_LIST_VIEW_ERROR 80 0x50 LDAP_OTHER 81 0x51 LDAP_SERVER_DOWN 82 0x52 LDAP_LOCAL_ERROR 83 0x53 LDAP_ENCODING_ERROR 84 0x54 LDAP_DECODING_ERROR 85 0x55 LDAP_TIMEOUT 86 0x56 LDAP_AUTH_UNKNOWN 87 0x57 LDAP_FILTER_ERROR 88 0x58 LDAP_USER_CANCELLED 89 0x59 LDAP_PARAM_ERROR 90 0x5A LDAP_NO_MEMORY 91 0x5B LDAP_CONNECT_ERROR 92 0x5C LDAP_NOT_SUPPORTED 93 0x5D LDAP_CONTROL_NOT_FOUND 94 0x5E LDAP_MORE_RESULTS_TO_RETURN 95 0x5F LDAP_MORE_RESULTS_TO_RETURN 96 0x60 LDAP_CLIENT_LOOP 97 0x61 LDAP_REFERRAL_LIMIT_EXCEEDED 118 0x76 LDAP_CANCELLED [a] LDAPv3 [b] Not used in LDAPv3 [c] Reserved for CLDAP 7.5. Replacing Log Files with a Named Pipe Many administrators want to do some special configuration or operation with logging data, like configuring an access log to record only certain events. This is not possible using the standard Directory Server log file configuration attributes, but it is possible by sending the log data to a named pipe, and then using another script to process the data. Using a named pipe for the log simplifies these special tasks, like: Logging certain events, like failed bind attempts or connections from specific users or IP addresses Logging entries which match a specific regular expression pattern Keeping the log to a certain length (logging only the last number of lines) Sending a notification, such as an email, when an event occurs Replacing a log file with a pipe improves performance, especially on servers with a high rate of operations. The named pipe is different than using a script to extract data from the logs because of how data are handled in the log buffer. If a log is buffered, server performance is good, but important data are not written to disk (the log file) as soon as the event occurs. If the server is having a problem with crashing, it may crash before the data is written to disk - and there is no data for the script to extract. If a log is not buffered [1] , the writes are flushed to disk with each operation, causing a lot of disk I/O and performance degradation. Replacing the log disk file with a pipe has the benefits of buffering, since the script that reads from the pipe can buffer the incoming log data in memory (which is not possible with a simple script). The usage and option details for the script is covered in Section 9.4, "ds-logpipe.py" . The basic format is: ds-logpipe.py /path/to/named_pipe --user pipe_user --maxlines number --serverpidfile file.pid --serverpid PID --servertimeout seconds --plugin= /path/to/plugin.py pluginfile.arg = value 7.5.1. Using the Named Pipe for Logging The Directory Server instance can use a named pipe for its logging simply by running the named pipe log script and giving the name of the pipe. (If the server is already running, then the log has to be reopened, but there is no configuration required otherwise.) Running the ds-logpipe.py in this way has the advantage of being simple to implement and not requiring any Directory Server configuration changes. This is useful for fast debugging or monitoring, especially if you are looking for a specific type of event. If the Directory Server instance will frequently or permanently use the named pipe rather than a real file for logging, then it is possible to reconfigure the instance to create the named pipe and use it for logging (as it does by default for the log files). Three things need to be configured for the log configuration for the instance: The log file to use has to be changed to the pipe ( nsslapd-*log , where the * can be access, error, or audit [2] , depending on the log type being configured) Buffering should be disabled because the script already buffers the log entries ( nsslapd-*log-logbuffering ) Log rotation should be disabled so that the server does not attempt to rotate the named pipe ( nsslapd-*log-maxlogsperdir , nsslapd-*log-logexpirationtime , and nsslapd-*log-logrotationtime ) These configuration changes can be made in the Directory Server Console or using ldapmodify . For example, this switches the access log to access.pipe : Note Making these changes causes the server to close the current log file and switch to the named pipe immediately. This can be very helpful for debugging a running server and sifting the log output for specific messages. 7.5.2. Starting the Named Pipe with the Server The named pipe can be started and shut down along with the Directory Server instance by editing the instance's init script configuration file. Note The named pipe script has to be specifically configured in the instance's dse.ldif file before it can be called at server startup. Open the instance configuration file for the server system. Warning Do not edit the /etc/sysconfig/dirsrv file. At the end of the file, there will be a line that reads: Below that line, insert the ds-logpipe.py command to launch when the server starts. For example: Note The -s option both specifies the .pid file for the server to write its PID to and sets the script to start and stop with the server process. 7.5.3. Using Plug-ins with the Named Pipe Log A plug-in can be called to read the log data from the named pipe and perform some operation on it. There are some considerations with using plug-ins with the named pipe log script: The plug-in function is called for every line read from the named pipe. The plug-in function must be a Python script and must end in .py . Any plug-in arguments are passed in the command line to the named pipe log script. A pre-operation function can be specified for when the plug-in is loaded. A post-operation function can be called for when the script exits. 7.5.3.1. Loading Plug-ins with the Named Pipe Log Script There are two options with ds-logpipe.py to use for plug-ins: The --plugin option gives the path to the plug-in file (which must be a Python script and must end in .py ). The plugin.arg option passes plug-in arguments to the named pipe log script. The plug-in file name (without the .py extension) is plugin and any argument allowed in that plug-in can be arg . For example: If there are more than one values passed for the same argument, then they are converted into a list of values in the plug-in dict. For example, this script gives two values for arg1 : In the plug-in, this is converted to: This is a Python dict object with two keys. The first key is the string arg1 , and its value is a Python list object with two elements, the strings foo and bar . The second key is the string arg2 , and its value is the string baz . If an argument has only a single value, it is left as a simple string. Multiple values for a single argument name are converted into a list of strings. 7.5.3.2. Writing Plug-ins to Use with the Named Pipe Log Script The ds-logpipe.py command expects up to three functions in any plug-in: plugin () , pre () , and post () . Any plug-in used with the ds-logpipe.py command must specify the plugin function. The plugin () function is performed against every line in the log data, while the pre () and post () functions are run when the script is started and stopped, respectively. Each function can have any arguments defined for it, and these arguments can then be passed to the script using the plugin.arg option. Additionally, each function can have its own return values and actions defined for it. Example 7.8. Simple Named Pipe Log Plug-in [1] Server performance suffers when log buffering is disabled on the access log, when the log level is changed on the error log, or with audit logging. [2] The audit log is not enabled by default, so this log has to be enabled before a named pipe can be used to replace it.

Commands:
[23/Jun/2020:16:30:27.388006333 -0400] conn=20 op=5 SRCH base="dc=example,dc=com" scope=2 filter="(&(objectClass=top)(objectClass=ldapsubentry)(objectClass=passwordpolicy))" attrs="distinguishedName"
[23/Jun/2020:16:30:27.390881301 -0400] conn=20 op=5 RESULT err=0 tag=101 nentries=0 wtime=0.000035342 optime=0.002877749 etime=0.002911121
[21/Apr/2020:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139 [21/Apr/2020:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory Manager" method=128 version=3 [21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0 [21/Apr/2020:11:39:51 -0700] conn=11 op=1 SRCH base="dc=example,dc=com" scope=2 filter="(mobile=+1 123 456-7890)" [21/Apr/2020:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 nentries=1 etime=3 notes=U [21/Apr/2020:11:39:51 -0700] conn=11 op=2 UNBIND [21/Apr/2020:11:39:51 -0700] conn=11 op=2 fd=608 closed - U1 [21/Apr/2020:11:39:52 -0700] conn=12 fd=634 slot=634 connection from 207.1.153.51 to 192.18.122.139 [21/Apr/2020:11:39:52 -0700] conn=12 op=0 BIND dn="cn=Directory Manager" method=128 version=3 [21/Apr/2020:11:39:52 -0700] conn=12 op=0 RESULT err=0 tag=97 nentries=0 etime=0 [21/Apr/2020:11:39:52 -0700] conn=12 op=1 SRCH base="dc=example,dc=com" scope=2 filter="(uid=bjensen)" [21/Apr/2020:11:39:52 -0700] conn=12 op=2 ABANDON targetop=1 msgid=2 nentries=0 etime=0 [21/Apr/2020:11:39:52 -0700] conn=12 op=3 UNBIND [21/Apr/2020:11:39:52 -0700] conn=12 op=3 fd=634 closed - U1 [21/Apr/2020:11:39:53 -0700] conn=13 fd=659 slot=659 connection from 207.1.153.51 to 192.18.122.139 [21/Apr/2020:11:39:53 -0700] conn=13 op=0 BIND dn="cn=Directory Manager" method=128 version=3 [21/Apr/2020:11:39:53 -0700] conn=13 op=0 RESULT err=0 tag=97 nentries=0 etime=0 [21/Apr/2020:11:39:53 -0700] conn=13 op=1 EXT oid="2.16.840.1.113730.3.5.3" [21/Apr/2020:11:39:53 -0700] conn=13 op=1 RESULT err=0 tag=120 nentries=0 etime=0 [21/Apr/2020:11:39:53 -0700] conn=13 op=2 ADD dn="cn=Sat Apr 21 11:39:51 MET DST 2020,dc=example,dc=com" [21/Apr/2020:11:39:53 -0700] conn=13 op=2 RESULT err=0 tag=105 nentries=0 etime=0 csn=3b4c8cfb000000030000 [21/Apr/2020:11:39:53 -0700] conn=13 op=3 EXT oid="2.16.840.1.113730.3.5.5" [21/Apr/2020:11:39:53 -0700] conn=13 op=3 RESULT err=0 tag=120 nentries=0 etime=0 [21/Apr/2020:11:39:53 -0700] conn=13 op=4 UNBIND [21/Apr/2020:11:39:53 -0700] conn=13 op=4 fd=659 closed - U1 [21/Apr/2020:11:39:55 -0700] conn=14 fd=700 slot=700 connection from 207.1.153.51 to 192.18.122.139 [21/Apr/2020:11:39:55 -0700] conn=14 op=0 BIND dn="" method=sasl version=3 mech=DIGEST-MD5 [21/Apr/2020:11:39:55 -0700] conn=14 op=0 RESULT err=14 tag=97 nentries=0 etime=0, SASL bind in progress [21/Apr/2020:11:39:55 -0700] conn=14 op=1 BIND dn="uid=jdoe,dc=example,dc=com" method=sasl version=3 mech=DIGEST-MD5 [21/Apr/2020:11:39:55 -0700] conn=14 op=1 RESULT err=0 tag=97nentries=0 etime=0 dn="uid=jdoe,dc=example,dc=com" [21/Apr/2020:11:39:55 -0700] conn=14 op=2 UNBIND [21/Apr/2020:11:39:53 -0700] conn=14 op=2 fd=700 closed - U1
[21/Apr/2020:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139
[21/Apr/2020:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139
[21/Apr/2020:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory Manager" method=128 version=3
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory Manager" method=128 version=3
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
[21/Apr/2020:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 nentries=1 etime=3 notes=U
[04/May/2020:15:51:46 -0700] conn=114 op=68 SORT serialno (1)
[21/Apr/2016:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 nentries=1 etime=3 notes=U
VLV RequestInformation ResponseInformation
beforeCount:afterCount:index:contentCount
targetPosition:contentCount ( resultCode )
[07/May/2020:11:43:29 -0700] conn=877 op=8530 SRCH base="(ou=People)" scope=2 filter="(uid=*)" [07/May/2020:11:43:29 -0700] conn=877 op=8530 SORT uid [07/May/2020:11:43:29 -0700] conn=877 op=8530 VLV 0:5:0210 10:5397 (0 ) [07/May/2020:11:43:29 -0700] conn=877 op=8530 RESULT err=0 tag=101 nentries=1 etime=0
[21/Apr/2020:11:39:52 -0700] conn=12 op=2 ABANDON targetop=1 msgid=2 nentries=0 etime=0
[21/Apr/2020:11:39:52 -0700] conn=12 op=2 ABANDON targetop=NOTFOUND msgid=2
[21/Apr/2020:11:39:52 -0700] conn=12 op=2 ABANDON targetop=NOTFOUND msgid=2
[21/Apr/2020:11:39:55 -0700] conn=14 op=0 BIND dn="" method=sasl version=3 mech=DIGEST-MD5 [21/Apr/2020:11:39:55 -0700] conn=14 op=0 RESULT err=14 tag=97 nentries=0 etime=0, SASL bind in progress
[21/Apr/2020:12:57:14 -0700] conn=32 op=0 BIND dn="" method=sasl version=3 mech=GSSAPI
[21/Apr/2020:11:39:55 -0700] conn=14 op=1 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=jdoe,dc=example,dc=com"
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 SRCH base="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"scope=0 filter="objectclass=nsMappingTree"attrs="nsslapd-referral" options=persistent [12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 RESULT err=0 tag=48 nentries=1etime=0 [12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 SRCH base="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"scope=0 filter="objectclass=nsMappingTree" attrs="nsslapd-state" [12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 RESULT err=0 tag=48 nentries=1etime=0
[12/Jul/2020:16:43:02 +0200] conn=306 fd=60 slot=60 connection from 127.0.0.1 to 127.0.0.1 [12/Jul/2020:16:43:02 +0200] conn=306 op=0 SRCH base="dc=example,dc=com" scope=2 filter="(description=*)" attrs=ALL [12/Jul/2020:16:43:02 +0200] conn=306 op=0 ENTRY dn="ou=Special [12/Jul/2020:16:43:02 +0200] conn=306 op=0 ENTRY dn="cn=Accounting Managers,ou=groups,dc=example,dc=com" [12/Jul/2020:16:43:02 +0200] conn=306 op=0 ENTRY dn="cn=HR Managers,ou=groups,dc=example,dc=com" [12/Jul/2020:16:43:02 +0200] conn=306 op=0 ENTRY dn="cn=QA Managers,ou=groups,dc=example,dc=com" [12/Jul/2020:16:43:02 +0200] conn=306 op=0 ENTRY dn="cn=PD Managers,ou=groups,dc=example,dc=com" [12/Jul/2020:16:43:02 +0200] conn=306 op=0 ENTRY dn="ou=Red Hat Servers,dc=example,dc=com" [12/Jul/2020:16:43:02 +0200] conn=306 op=0 REFERRAL
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 ENTRY dn="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 SRCH base="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"scope=0 filter="objectclass=nsMappingTree"attrs="nsslapd-referral" options=persistent
time_stamp - severity_level - function_name - message
[24/Mar/2017:11:31:38.781466443 +0100] - ERR - no_diskspace - No enough space left on device (/var/lib/dirsrv/slapd- instance_name /db) (40009728 bytes); at least 145819238 bytes space is needed for db region files
time_stamp - severity_level - plug-in_name - function_name - message
[24/Mar/2017:11:42:17.628363848 +0100] - ERR - NSMMReplicationPlugin - multimaster_extop_StartNSDS50ReplicationRequest - conn=19 op=3 repl="o= example.com ": Excessive clock skew from supplier RUV
grep ERR /var/log/dirsrv/slapd- instance_name /errors [24/Mar/2017:11:31:38.781466443 +0100] - ERR - no_diskspace - No enough space left on device (/var/lib/dirsrv/slapd- instance_name /db) (40009728 bytes); at least 145819238 bytes space is needed for db region files [24/Mar/2017:11:31:38.815623298 +0100] - ERR - ldbm_back_start - Failed to init database, err=28 No space left on device [24/Mar/2017:11:31:38.828591835 +0100] - ERR - plugin_dependency_startall - Failed to start database plugin ldbm database
[ timestamp ] NSMMReplicationPlugin - agmt=" name " ( consumer_host:consumer_port ): current_task
[09/Jan/2020:13:44:48 -0500] NSMMReplicationPlugin - agmt="cn=example2" (alt:13864): {replicageneration} 4949df6e000000010000
[29/May/2017:14:15:30.539817639 +0200] - DEBUG - _csngen_adjust_local_time - gen state before 592c103d0000:1496059964:0:1 [29/May/2017:14:15:30.562983285 +0200] - DEBUG - _csngen_adjust_local_time - gen state after 592c10e20000:1496060129:0:1 [29/May/2017:14:15:30.578828393 +0200] - DEBUG - NSMMReplicationPlugin - ruv_add_csn_inprogress - Successfully inserted csn 592c10e2000000020000 into pending list [29/May/2017:14:15:30.589917123 +0200] - DEBUG - NSMMReplicationPlugin - changelog program - _cl5GetDBFileByReplicaName - found DB object 0x558ddfe1f720 for database /var/lib/dirsrv/slapd-supplier_2/changelogdb/d3de3e8d-446611e7-a89886da-6a37442d_592c0e0b000000010000.db [29/May/2017:14:15:30.600044236 +0200] - DEBUG - NSMMReplicationPlugin - changelog program - cl5WriteOperationTxn - Successfully written entry with csn (592c10e2000000020000) [29/May/2017:14:15:30.615923352 +0200] - DEBUG - NSMMReplicationPlugin - changelog program - _cl5GetDBFileByReplicaName - found DB object 0x558ddfe1f720 for database /var/lib/dirsrv/slapd-supplier_2/changelogdb/d3de3e8d-446611e7-a89886da-6a37442d_592c0e0b000000010000.db [29/May/2017:14:15:30.627443305 +0200] - DEBUG - NSMMReplicationPlugin - csnplCommitALL: committing all csns for csn 592c10e2000000020000 [29/May/2017:14:15:30.632713657 +0200] - DEBUG - NSMMReplicationPlugin - csnplCommitALL: processing data csn 592c10e2000000020000 [29/May/2017:14:15:30.652621188 +0200] - DEBUG - NSMMReplicationPlugin - ruv_update_ruv - Successfully committed csn 592c10e2000000020000 [29/May/2017:14:15:30.669666453 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_run - agmt="cn=meTo_localhost:39001" (localhost:39001): State: wait_for_changes -> wait_for_changes [29/May/2017:14:15:30.685259483 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_run - agmt="cn=meTo_localhost:39001" (localhost:39001): State: wait_for_changes -> ready_to_acquire_replica [29/May/2017:14:15:30.689906327 +0200] - DEBUG - NSMMReplicationPlugin - conn_connect - agmt="cn=meTo_localhost:39001" (localhost:39001) - Trying non-secure slapi_ldap_init_ext [29/May/2017:14:15:30.700259799 +0200] - DEBUG - NSMMReplicationPlugin - conn_connect - agmt="cn=meTo_localhost:39001" (localhost:39001) - binddn = cn=replrepl,cn=config, passwd = {AES-TUhNR0NTcUdTSWIzRFFFRkRUQm1NRVVHQ1NxR1NJYjNEUUVGRERBNEJDUmlZVFUzTnpRMk55MDBaR1ZtTXpobQ0KTWkxaE9XTTRPREpoTlMwME1EaGpabVUxWmdBQ0FRSUNBU0F3Q2dZSUtvWklodmNOQWdjd0hRWUpZSVpJQVdVRA0KQkFFcUJCRGhwMnNLcEZ2ZWE2RzEwWG10OU41Tg==}+36owaI7oTmvWhxRzUqX5w== [29/May/2017:14:15:30.712287531 +0200] - DEBUG - NSMMReplicationPlugin - conn_cancel_linger - agmt="cn=meTo_localhost:39001" (localhost:39001) - No linger to cancel on the connection [29/May/2017:14:15:30.736779494 +0200] - DEBUG - _csngen_adjust_local_time - gen state before 592c10e20001:1496060129:0:1 [29/May/2017:14:15:30.741909244 +0200] - DEBUG - _csngen_adjust_local_time - gen state after 592c10e30000:1496060130:0:1 [29/May/2017:14:15:30.880287041 +0200] - DEBUG - NSMMReplicationPlugin - acquire_replica - agmt="cn=meTo_localhost:39001" (localhost:39001): Replica was successfully acquired. [29/May/2017:14:15:30.897500049 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_run - agmt="cn=meTo_localhost:39001" (localhost:39001): State: ready_to_acquire_replica -> sending_updates [29/May/2017:14:15:30.914417773 +0200] - DEBUG - csngen_adjust_time - gen state before 592c10e30001:1496060130:0:1 [29/May/2017:14:15:30.926341721 +0200] - DEBUG - NSMMReplicationPlugin - changelog program - _cl5GetDBFile - found DB object 0x558ddfe1f720 for database /var/lib/dirsrv/slapd-supplier_2/changelogdb/d3de3e8d-446611e7-a89886da-6a37442d_592c0e0b000000010000.db [29/May/2017:14:15:30.943094471 +0200] - DEBUG - NSMMReplicationPlugin - changelog program - _cl5PositionCursorForReplay - (agmt="cn=meTo_localhost:39001" (localhost:39001)): Consumer RUV: [29/May/2017:14:15:30.949395331 +0200] - DEBUG - NSMMReplicationPlugin - agmt="cn=meTo_localhost:39001" (localhost:39001): {replicageneration} 592c0e0b000000010000 [29/May/2017:14:15:30.961118175 +0200] - DEBUG - NSMMReplicationPlugin - agmt="cn=meTo_localhost:39001" (localhost:39001): {replica 1 ldap://localhost:39001} 592c0e17000000010000 592c0e1a000100010000 00000000 [29/May/2017:14:15:30.976680025 +0200] - DEBUG - NSMMReplicationPlugin - agmt="cn=meTo_localhost:39001" (localhost:39001): {replica 2 ldap://localhost:39002} 592c103c000000020000 592c103c000000020000 00000000 [29/May/2017:14:15:30.990404183 +0200] - DEBUG - NSMMReplicationPlugin - changelog program - _cl5PositionCursorForReplay - (agmt="cn=meTo_localhost:39001" (localhost:39001)): Supplier RUV: [29/May/2017:14:15:31.001242624 +0200] - DEBUG - NSMMReplicationPlugin - agmt="cn=meTo_localhost:39001" (localhost:39001): {replicageneration} 592c0e0b000000010000 [29/May/2017:14:15:31.017406105 +0200] - DEBUG - NSMMReplicationPlugin - agmt="cn=meTo_localhost:39001" (localhost:39001): {replica 2 ldap://localhost:39002} 592c103c000000020000 592c10e2000000020000 592c10e1 [29/May/2017:14:15:31.028803190 +0200] - DEBUG - NSMMReplicationPlugin - agmt="cn=meTo_localhost:39001" (localhost:39001): {replica 1 ldap://localhost:39001} 592c0e1a000100010000 592c0e1a000100010000 00000000 [29/May/2017:14:15:31.040172464 +0200] - DEBUG - agmt="cn=meTo_localhost:39001" (localhost:39001) - clcache_get_buffer - found thread private buffer cache 0x558ddf870f00 [29/May/2017:14:15:31.057495165 +0200] - DEBUG - agmt="cn=meTo_localhost:39001" (localhost:39001) - clcache_get_buffer - _pool is 0x558ddfe294d0 _pool->pl_busy_lists is 0x558ddfab84c0 _pool->pl_busy_lists->bl_buffers is 0x558ddf870f00 [29/May/2017:14:15:31.063015498 +0200] - DEBUG - agmt="cn=meTo_localhost:39001" (localhost:39001) - clcache_initial_anchorcsn - agmt="cn=meTo_localhost:39001" (localhost:39001) - (cscb 0 - state 0) - csnPrevMax () csnMax (592c10e2000000020000) csnBuf (592c103c000000020000) csnConsumerMax (592c103c000000020000) [29/May/2017:14:15:31.073252305 +0200] - DEBUG - clcache_initial_anchorcsn - anchor is now: 592c103c000000020000 [29/May/2017:14:15:31.089915209 +0200] - DEBUG - NSMMReplicationPlugin - changelog program - agmt="cn=meTo_localhost:39001" (localhost:39001): CSN 592c103c000000020000 found, position set for replay [29/May/2017:14:15:31.095825439 +0200] - DEBUG - agmt="cn=meTo_localhost:39001" (localhost:39001) - clcache_get_next_change - load=1 rec=1 csn=592c10e2000000020000 [29/May/2017:14:15:31.100123762 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_result_threadmain - Starting [29/May/2017:14:15:31.115749709 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_result_threadmain - Read result for message_id 0 [29/May/2017:14:15:31.125866330 +0200] - DEBUG - NSMMReplicationPlugin - replay_update - agmt="cn=meTo_localhost:39001" (localhost:39001): Sending add operation (dn="cn=user,ou=People,dc=example,dc=com" csn=592c10e2000000020000) [29/May/2017:14:15:31.142339398 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_result_threadmain - Read result for message_id 0 [29/May/2017:14:15:31.160456597 +0200] - DEBUG - NSMMReplicationPlugin - replay_update - agmt="cn=meTo_localhost:39001" (localhost:39001): Consumer successfully sent operation with csn 592c10e2000000020000 [29/May/2017:14:15:31.172399536 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_result_threadmain - Read result for message_id 0 [29/May/2017:14:15:31.188857336 +0200] - DEBUG - agmt="cn=meTo_localhost:39001" (localhost:39001) - clcache_adjust_anchorcsn - agmt="cn=meTo_localhost:39001" (localhost:39001) - (cscb 0 - state 1) - csnPrevMax (592c10e2000000020000) csnMax (592c10e2000000020000) csnBuf (592c10e2000000020000) csnConsumerMax (592c10e2000000020000) [29/May/2017:14:15:31.199605024 +0200] - DEBUG - agmt="cn=meTo_localhost:39001" (localhost:39001) - clcache_load_buffer - rc=-30988 [29/May/2017:14:15:31.210800816 +0200] - DEBUG - NSMMReplicationPlugin - send_updates - agmt="cn=meTo_localhost:39001" (localhost:39001): No more updates to send (cl5GetNextOperationToReplay) [29/May/2017:14:15:31.236214134 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_waitfor_async_results - 0 5 [29/May/2017:14:15:31.246755544 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_result_threadmain - Read result for message_id 0 [29/May/2017:14:15:31.277705986 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_result_threadmain - Read result for message_id 0 [29/May/2017:14:15:31.303530336 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_result_threadmain - Read result for message_id 5 [29/May/2017:14:15:31.318259308 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_result_threadmain - Result 1, 0, 0, 5, (null) [29/May/2017:14:15:31.335263462 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_result_threadmain - Read result for message_id 5 [29/May/2017:14:15:31.364551307 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_waitfor_async_results - 5 5 [29/May/2017:14:15:31.376301820 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_result_threadmain exiting [29/May/2017:14:15:31.393707037 +0200] - DEBUG - agmt="cn=meTo_localhost:39001" (localhost:39001) - clcache_return_buffer - session end: state=5 load=1 sent=1 skipped=0 skipped_new_rid=0 skipped_csn_gt_cons_maxcsn=0 skipped_up_to_date=0 skipped_csn_gt_ruv=0 skipped_csn_covered=0 [29/May/2017:14:15:31.398134114 +0200] - DEBUG - NSMMReplicationPlugin - consumer_connection_extension_acquire_exclusive_access - conn=4 op=3 Acquired consumer connection extension [29/May/2017:14:15:31.423099625 +0200] - DEBUG - NSMMReplicationPlugin - multimaster_extop_StartNSDS50ReplicationRequest - conn=4 op=3 repl="dc=example,dc=com": Begin incremental protocol [29/May/2017:14:15:31.438899389 +0200] - DEBUG - csngen_adjust_time - gen state before 592c10e30001:1496060130:0:1 [29/May/2017:14:15:31.443800884 +0200] - DEBUG - csngen_adjust_time - gen state after 592c10e40001:1496060130:1:1 [29/May/2017:14:15:31.454123488 +0200] - DEBUG - NSMMReplicationPlugin - replica_get_exclusive_access - conn=4 op=3 repl="dc=example,dc=com": Acquired replica [29/May/2017:14:15:31.469698781 +0200] - DEBUG - NSMMReplicationPlugin - release_replica - agmt="cn=meTo_localhost:39001" (localhost:39001): Successfully released consumer [29/May/2017:14:15:31.475096195 +0200] - DEBUG - NSMMReplicationPlugin - conn_start_linger -agmt="cn=meTo_localhost:39001" (localhost:39001) - Beginning linger on the connection [29/May/2017:14:15:31.485281588 +0200] - DEBUG - NSMMReplicationPlugin - repl5_inc_run - agmt="cn=meTo_localhost:39001" (localhost:39001): State: sending_updates -> wait_for_changes [29/May/2017:14:15:31.495865065 +0200] - DEBUG - NSMMReplicationPlugin - multimaster_extop_StartNSDS50ReplicationRequest - conn=4 op=3 repl="dc=example,dc=com": StartNSDS90ReplicationRequest: response=0 rc=0 [29/May/2017:14:15:31.501617765 +0200] - DEBUG - NSMMReplicationPlugin - consumer_connection_extension_relinquish_exclusive_access - conn=4 op=3 Relinquishing consumer connection extension [29/May/2017:14:15:31.716627741 +0200] - DEBUG - NSMMReplicationPlugin - consumer_connection_extension_acquire_exclusive_access - conn=4 op=4 Acquired consumer connection extension [29/May/2017:14:15:31.735431913 +0200] - DEBUG - NSMMReplicationPlugin - replica_relinquish_exclusive_access - conn=4 op=4 repl="dc=example,dc=com": Released replica held by locking_purl=conn=4 id=3 [29/May/2017:14:15:31.745841821 +0200] - DEBUG - NSMMReplicationPlugin - consumer_connection_extension_relinquish_exclusive_access - conn=4 op=4 Relinquishing consumer connection extension
[ timestamp ] Plugin_name - message [ timestamp ] - function - message
[29/May/2017:14:38:19.133878244 +0200] - DEBUG - get_filter_internal - ==> [29/May/2017:14:38:19.153942547 +0200] - DEBUG - get_filter_internal - PRESENT [29/May/2017:14:38:19.177908064 +0200] - DEBUG - get_filter_internal - <= 0 [29/May/2017:14:38:19.193547449 +0200] - DEBUG - slapi_vattr_filter_test_ext_internal - => [29/May/2017:14:38:19.198121765 +0200] - DEBUG - slapi_vattr_filter_test_ext_internal - <= [29/May/2017:14:38:19.214342752 +0200] - DEBUG - slapi_vattr_filter_test_ext_internal - PRESENT [29/May/2017:14:38:19.219886104 +0200] - DEBUG - NSACLPlugin - acl_access_allowed - conn=15 op=1 (main): Allow search on entry(cn=replication,cn=config): root user [29/May/2017:14:38:19.230152526 +0200] - DEBUG - slapi_vattr_filter_test_ext_internal - <= 0 [29/May/2017:14:38:19.240971955 +0200] - DEBUG - NSACLPlugin - acl_read_access_allowed_on_entry - Root access (read) allowed on entry(cn=replication,cn=config) [29/May/2017:14:38:19.246456160 +0200] - DEBUG - cos-plugin - cos_cache_vattr_types - Failed to get class of service reference [29/May/2017:14:38:19.257200851 +0200] - DEBUG - NSACLPlugin - Root access (read) allowed on entry(cn=replication,cn=config) [29/May/2017:14:38:19.273534025 +0200] - DEBUG - NSACLPlugin - Root access (read) allowed on entry(cn=replication,cn=config) [29/May/2017:14:38:19.289474926 +0200] - DEBUG - slapi_filter_free - type 0x87
[29/May/2017:15:26:48.897935879 +0200] - DEBUG - collation_read_config - Reading config file /etc/dirsrv/slapd-supplier_1/slapd-collations.conf [29/May/2017:15:26:48.902606586 +0200] - DEBUG - collation-plugin - collation_read_config - line 16: collation "" "" "" 1 3 2.16.840.1.113730.3.3.2.0.1 default [29/May/2017:15:26:48.918493657 +0200] - DEBUG - collation-plugin - collation_read_config - line 17: collation ar "" "" 1 3 2.16.840.1.113730.3.3.2.1.1 ar [29/May/2017:15:26:48.932550086 +0200] - DEBUG - collation-plugin - collation_read_config - line 18: collation be "" "" 1 3 2.16.840.1.113730.3.3.2.2.1 be be-BY
[29/May/2017:15:34:52.742034888 +0200] - DEBUG - NSACLPlugin - acllist_init_scan - Failed to find root for base: cn=features,cn=config [29/May/2017:15:34:52.761702767 +0200] - DEBUG - NSACLPlugin - acllist_init_scan - Failed to find root for base: cn=config [29/May/2017:15:34:52.771907825 +0200] - DEBUG - NSACLPlugin - acl_access_allowed - #### conn=6 op=1 binddn="cn=user,ou=people,dc=example,dc=com" [29/May/2017:15:34:52.776327012 +0200] - DEBUG - NSACLPlugin - ************ RESOURCE INFO STARTS ********* [29/May/2017:15:34:52.786397852 +0200] - DEBUG - NSACLPlugin - Client DN: cn=user,ou=people,dc=example,dc=com [29/May/2017:15:34:52.797004451 +0200] - DEBUG - NSACLPlugin - resource type:256(search target_DN ) [29/May/2017:15:34:52.807135945 +0200] - DEBUG - NSACLPlugin - Slapi_Entry DN: cn=features,cn=config [29/May/2017:15:34:52.822877838 +0200] - DEBUG - NSACLPlugin - ATTR: objectClass [29/May/2017:15:34:52.827250828 +0200] - DEBUG - NSACLPlugin - rights:search [29/May/2017:15:34:52.831603634 +0200] - DEBUG - NSACLPlugin - ************ RESOURCE INFO ENDS ********* [29/May/2017:15:34:52.847183276 +0200] - DEBUG - NSACLPlugin - acl__scan_for_acis - Num of ALLOW Handles:0, DENY handles:0 [29/May/2017:15:34:52.857857195 +0200] - DEBUG - NSACLPlugin - print_access_control_summary - conn=6 op=1 (main): Deny search on entry(cn=features,cn=config).attr(objectClass) to cn=user,ou=people,dc=example,dc=com: no aci matched the resource
timestamp: date dn: modified_entry changetype: action action : attribute attribute : new_value - replace: modifiersname modifiersname: dn - replace: modifytimestamp modifytimestamp: date -
... modifying an entry time: 20200108181429 dn: uid=scarter,ou=people,dc=example,dc=com changetype: modify replace: userPassword userPassword: {SSHA}8EcJhJoIgBgY/E5j8JiVoj6W3BLyj9Za/rCPOw== - replace: modifiersname modifiersname: cn=Directory Manager - replace: modifytimestamp modifytimestamp: 20200108231429Z - ... sending a replication update time: 20200109131811 dn: cn=example2,cn=replica,cn="dc=example,dc=com",cn=mapping tree,cn=config changetype: modify replace: nsds5BeginReplicaRefresh nsds5BeginReplicaRefresh: start - replace: modifiersname modifiersname: cn=Directory Manager - replace: modifytimestamp modifytimestamp: 20200109181810Z -
ds-logpipe.py /var/log/dirsrv/slapd-example/access
ldapmodify -D "cn=Directory Manager" -W -p 389 -h server.example.com -x dn: cn=config changetype: modify replace: nsslapd-accesslog nsslapd-accesslog: /var/log/dirsrv/slapd- instance /access.pipe - replace: nsslapd-accesslog-logbuffering nsslapd-accesslog-logbuffering: off - replace: nsslapd-accesslog-maxlogsperdir nsslapd-accesslog-maxlogsperdir: 1 - replace: nsslapd-accesslog-logexpirationtime nsslapd-accesslog-logexpirationtime: -1 - replace: nsslapd-accesslog-logrotationtime nsslapd-accesslog-logrotationtime: -1
/etc/sysconfig/dirsrv- instance_name
Put custom instance specific settings below here.
only keep the last 1000 lines of the error log python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-example/errors.pipe -m 1000 -u dirsrv -s /var/run/dirsrv/slapd-example.pid > /var/log/dirsrv/slapd-example/errors & only log failed binds python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-example/access.pipe -u dirsrv -s /var/run/dirsrv/slapd-example.pid --plugin=/usr/share/dirsrv/data/failedbinds.py failedbinds.logfile=/var/log/dirsrv/slapd-example/access.failedbinds &
ds-logpipe.py /var/log/dirsrc/slapd-example/errors.pipe --plugin=/usr/share/dirsrv/data/example-funct.py example-funct.regex="warning" > warnings.txt
--plugin=/path/to/pluginname.py pluginname.arg1=foo pluginname.arg1=bar pluginname.arg2=baz
{'arg1': ['foo', 'bar'], 'arg2': 'baz'}
def pre(myargs): retval = True myarg = myargs['argname'] if isinstance(myarg, list): # handle list of values else: # handle single value if bad_problem: retval = False return retval def plugin(line): retval = True # do something with line if something_is_bogus: retval = False return retval def post(): # no arguments # do something # no return value