Directory Proxy Server logs information in access logs and error logs. Additionally, a plug-in can be configured to log messages to a syslog daemon. Unlike Directory Server, Directory Proxy Server does not provide an audit log.
Log files for Directory Proxy Server can be configured through Directory Service Control Center or on the command line. For information about how to configure log files, see Chapter 27, Directory Proxy Server Logging, in Sun Java System Directory Server Enterprise Edition 6.2 Administration Guide.
For information about access logs and error logs, see the following sections:
Note that the log message format is still evolving in this release of Directory Proxy Server.
The Directory Proxy Server logging service provides access logs and error logs. The logs are flat files that contain information about client operations and about the health of Directory Proxy Server. By default, log files are stored under instance-path/logs with the permission of 600. If an instance of Directory Proxy Server is started without valid log files, log files are created in the default location and a warning is sent to DSCC.
You can configure the following aspects of the logs:
Set the log level for each message category
Globally set the default log-level for all message categories
Globally enable all logs
Set the name, location and permissions of log files
Set the maximum number of log files
Define a rotation policy for each log file
Include or exclude search filters in access log messages for search operations
Log messages can also be sent to the syslog daemon. For information about how to log messages to a syslog daemon, see Logging Alerts to the syslogd Daemon in Sun Java System Directory Server Enterprise Edition 6.2 Administration Guide.
Log files can be rotated manually at any time, or can be rotated automatically when the following events occur:
When the log reaches a specified size
At a specified start-time, start-day, and interval
At a specified start-time, start-day, and interval, if the log file is bigger than a specified size
The start-time, start-day, and interval can have the following combinations:
Time-of-day followed by an interval of days, hours, or minutes
Day-of-week and time-of-day, followed by an interval of weeks
Day-of-month and time-of-day, followed by an interval of months
The time-of-day takes precedence over the interval. For example, a log that is specified to be rotated at 3am and then every 10 hours is rotated at the following times: 03:00, 13:00, 23:00, and again at 03:00 (not 07:00).
If the log is configured for rotation on the 31st of the month but the month has fewer than 31 days, the log is rotated on the first day of the following month.
A log file deletion policy defines when backup log files are deleted. The log file currently in use is never deleted by a deletion policy.
The following deletion policies can be enabled:
Deletion based on time. Log files are deleted when they reach a specified age.
Deletion based on size. Log files are deleted when the total size of all the log files reaches a specified limit. The size of the current log file is taken into account, although this file is not deleted.
Deletion based on free disk space. When the free disk space reaches a specified minimum, the oldest backup log file is deleted. If the free disk space is still lower than the minimum, the next oldest backup log file is deleted, and so forth.
By default, log file deletion is based on free disk space, with a default value of 1 Megabyte. When all three deletion policies are activated simultaneously, they are processed in order of time, size, and free disk space. For information about how to configure log file deletion, see Deleting Directory Proxy Server Logs in Sun Java System Directory Server Enterprise Edition 6.2 Administration Guide.
Messages are included in log files or filtered out of log files according to the severity of the message, the category of the message, and the log-level that has been configured for that category. The categories and log-levels for the error logs and access logs are different, and are discussed in the sections that follow.
Messages are ranked according to their severity. Messages can have one of the following severities, where error is highest severity and debug is the lowest severity:
error
warning
info
debug
Messages with a severity that is lower than the log-level configured for its message category are not included in the log file. Messages with a severity that is equal to or higher than the log-level configured for its associated message category are included in the log file.
Error logs contain information about the health of the Directory Proxy Server. Error messages are categorized according to the cause of the message. The following table lists the categories of messages that can be included in an error log.
Table 23–1 Message Categories for Error Logs
Category Name |
Category Description |
---|---|
CONFIG |
Information about configuration |
DECODE |
Information about operation decoding |
PLUGIN |
Information about plug-in processing |
PROCESSING |
Information about a significant event that occurred during client processing |
BACKEND |
Information about an operation with a data source |
INTERNAL |
Information about an internal error in the core server |
SHUTDOWN |
Information about an event at server shutdown |
STARTUP |
Information about an event at server startup |
Each message category can be configured with one of the following log-levels:
none No messages are included in the log file.
error Only error messages are included in the log file.
warning Error messages and warning messages are included in the log file.
info Errors, warnings and informational messages are included in the log file.
all All messages are included in the log file. In most cases, this setting produces the same results as the info setting. In certain situations, this setting enables additional debugging messages to be logged.
inherited The log level is inherited from the value of the default-log-level property.
By default, the log level for each message category is info.
The log-level of a message category works in conjunction with the severity level of a message to determine which messages are included in the log file. For more information, see Message Severity.
An error log message has this format:
timestamp - message category - message severity - message text
Example 23–1 shows an extract from an error log.
[07/26/2005:10:41:38 +0200] - STARTUP - INFO - Sun Java(TM) System Directory Proxy Server/6.1 (Build 0719051656 DEBUG) starting up [07/26/2005:10:41:43 +0200] - STARTUP - INFO - Global log level INFO [07/26/2005:10:41:43 +0200] - STARTUP - INFO - Logging Service conf [07/26/2005:10:41:43 +0200] - STARTUP - INFO - Java Version: 1.5.0_03 (Java Home: /usr/lang/JAVA/jdk1.5.0_03/solaris-sparc/jre) [07/26/2005:10:41:43 +0200] - STARTUP - INFO - Operating System: [07/26/2005:10:41:43 +0200] - STARTUP - INFO - Init LDAP server cn=Server-1, cn=LDAP servers,cn=config [07/26/2005:10:41:43 +0200] - STARTUP - INFO - Init LDAP server cn=Server-2,cn=LDAP servers,cn=config [07/26/2005:10:41:43 +0200] - STARTUP - INFO - Init LDAP server cn=Server-3, cn=LDAP servers,cn=config [07/26/2005:10:41:44 +0200] - STARTUP - INFO - Performing SSL init [07/26/2005:10:41:44 +0200] - STARTUP - INFO - Creating 20 worker threads [07/26/2005:10:41:44 +0200] - PLUGIN - WARN - Unable to load plugin class com.sun.directory.proxy.plugin.StartTLSExtendedOpPlugin specified in plugin entry cn=1.3.6.1.4.1.1466.20037,cn=Plugins,cn=config -- not loading plugin. [07/26/2005:10:41:45 +0200] - STARTUP - INFO - Starting client listeners [07/26/2005:10:41:45 +0200] - STARTUP - INFO - Sun Java(TM) System Directory Proxy Server/6.1 (Build 0719051656 DEBUG) started on host a [07/26/2005:10:41:45 +0200] - STARTUP - INFO - Listening for secure client connections on 0.0.0.0:9636 [07/26/2005:10:41:45 +0200] - STARTUP - INFO - Listening for client connections on 0.0.0.0:9389 [07/26/2005:10:42:13 +0200] - BACKEND - WARN - Proactive Monitor thread determined that directory server ldap://nautilus:6389/ avail [07/26/2005:10:42:13 +0200] - BACKEND - WARN - Proactive Monitor thread determined directory server ldap://nautilus:7389/ is available. [07/26/2005:10:42:13 +0200] - BACKEND - WARN - Proactive Monitor thread determined directory server ldap://nautilus:5389/ is available. |
Access logs contain information about the requests being processed by Directory Proxy Server. Access logs contain information about two types of connection:
Connections between clients and Directory Proxy Server
Connections between Directory Proxy Server and data sources
Access log messages are categorized according to the cause of the message. The following table lists the categories of messages that can be included in the access log.
Table 23–2 Message Categories for Access Logs
Category Name |
Category Description |
---|---|
CONNECT |
Information about a client connection |
DISCONNECT |
Information about a client disconnection |
OPERATION |
Information about operations requested by a client |
PROFILE |
Information about the profiles of a connection handler |
SERVER_OP |
Information about operations that are forwarded to data sources |
SERVER_OP_DETAIL |
Detailed information about operations that are forwarded to data sources |
Each message category can be configured with one of the following log-levels:
none No access messages are included in the log file.
info Informational messages are included in the log file.
all All messages are included in the log file. In most cases, this setting produces the same results as the info setting. In certain situations, this setting enables additional debugging messages to be logged.
inherited The log level is inherited from the value of the default-log-level property.
By default, the log level for each message category is info.
The log-level of a message category works in conjunction with the severity level of a message to determine which messages are included in the log file. For more information, see Message Severity.
An access log message has this format:
timestamp - category - severity - connectionNumber operationNumber messageID operationType messageText
Example 23–2 shows an extract of an access log. The log shows a client request that starts with a message in the CONNECT category and ends with a message in the DISCONNECT category. The operation requested by the client is shown by the message in the OPERATION category, and results in several messages in the SERVER_OP category. The logged messages have the INFO and DEBUG severity.
[07/17/2005:17:29:45 +0200] - CONNECT - INFO - conn=1591031 client=129.157.192.132:49216 server=0.0.0.0:9389 protocol=LDAP [07/17/2005:17:29:45 +0200] - OPERATION - INFO - conn=1591031 op=0 msgid=1 SEARCH base="o=movie" scope=2 filter="(objectClass=*)" [07/17/2005:17:29:45 +0200] - SERVER_OP - INFO - conn=1591031 op=0 SEARCH base="o=movie" scope=2 filter="(objectClass=*)" s_msgid=318022 s_authzid="" s_conn=39 [07/17/2005:17:29:45 +0200] - SERVER_OP - INFO - conn=1591031 op=0 SEARCH base="o=movie" scope=2 filter="(objectClass=*)" s_msgid=316902 s_authzid="" s_conn=76 [07/17/2005:17:29:45 +0200] - SERVER_OP - INFO - conn=1591031 op=0 SEARCH RESPONSE err=0 msg="" nentries=4 s_conn=76 [07/17/2005:17:29:45 +0200] - SERVER_OP - DEBUG - Global status code = 0 [07/17/2005:17:29:45 +0200] - SERVER_OP - INFO - conn=1591031 op=0 SEARCH RESPONSE err=0 msg="" nentries=11 s_conn=39 [07/17/2005:17:29:45 +0200] - SERVER_OP - DEBUG - Global status code = 0 [07/17/2005:17:29:45 +0200] - OPERATION - INFO - conn=1591031 op=0 SEARCH RESPONSE err=0 msg="" nentries=22 [07/17/2005:17:29:45 +0200] - OPERATION - INFO - conn=1591031 op=1 UNBIND [07/17/2005:17:29:45 +0200] - DISCONNECT - INFO - conn=1591031 reason=unbind" |
Messages for the connections between a client and the Directory Proxy Server are labeled in the same way as in Directory Server. Table 23–4 describes parts of the messages between the client and the Directory Proxy Server in Example 23–2. For an explanation of all of the possible message parts, see Content of Access, Error, and Audit Logs.
Table 23–3 Message Parts for Connections Between a Client and a Directory Proxy Server
Log Message Part |
Description |
---|---|
conn |
Identifier for the connection between the client and the Directory Proxy Server. |
op |
The number of an operation on a given connection. The first operation on a connection has the value op=0. Subsequent requests on the connection have increasing numbers, op=1, op=2, etc. |
msgid |
The number of a message to be sent to a client application. The LDAP protocol is mainly asynchronous. If a client request requires a response from a server, the response is given in the following steps:
A response can be sent in multiple packets, where each packet is identified by the same msgid. |
nentries |
The number of entries returned by a search request. |
err |
The result code returned from the LDAP operation. The error number 0 means that the operation was successful. For a list of LDAP result codes, see Result Codes in Log Files. |
msg |
A human readable error diagnostic. |
Messages for the connections between Directory Proxy Server and a data source are prefixed with s_. Table 23–4 describes parts of the messages between the Directory Proxy Server and the data source in Example 23–2.
Table 23–4 Message Parts for Connections Between a Directory Proxy Server and a Data Source
Log Message Part |
Description |
---|---|
s_msgid |
Identifier for the message between the Directory Proxy Server and a data source. |
s_authzid |
Authorization identity for an operation to be processed under when the Directory Proxy Server forwards the request to a data source by using proxy authorization. |
s_conn |
Identifier for the connection between the Directory Proxy Server and the data source. |
Access log messages are stored in a buffer. The buffer is flushed to the access log at the following times:
When the buffer is full
When the access log is rotated
When Directory Proxy Server is stopped
If a buffer is flushed because it is full, the last message in the access log file might not be complete. The remainder of the message is then delivered in the next flush. By default, the size of the buffer is 10 KBytes. However, the size of the buffer can be configured to control the frequency with which it is flushed. For performance reasons, the buffer size should not be reduced to less than 5 KBytes.
You can configure the size of the access log buffer by setting the log-buffer-size property. For information about how to configure access log properties, see Configuring Directory Proxy Server Logs in Sun Java System Directory Server Enterprise Edition 6.2 Administration Guide.
Access logs show client accesses to the server and corresponding server responses. Directory Proxy Server access logs further show information about the connections set up against data sources, in this case Directory Server instances.
Tracking client requests can be broken down into the following steps:
Tracking the operations performed within a single client connection
Identifying the client that performed a certain operation
Directory Proxy Server typically sets up connections with backend servers before it handles client connections. This means that the proxy can pool operations, binding and rebinding only when necessary and avoiding connection setup overhead. Directory Proxy Server identifies these backend connections in its access log with tags of the form s_conn=data-source:number, where data-source is a data source name from the configuration and number is a server connection number assigned by the proxy. Such s_conn server connections can then be matched to connection numbers in Directory Server access logs using the port number from which the proxy connected to the directory as a client when establishing the connection. Therefore, s_conn in proxy access log messages be translated into conn in directory access log messages.
In the Directory Proxy Server access log, each client operation is contained within a CONNECT and a DISCONNECT message. Between these two messages, several OPERATION messages can appear. Each OPERATION message can contain several SERVER_OP messages.
The OPERATION messages refer to operations performed by the client. The SERVER_OP messages refer to operations performed by Directory Proxy Server.
The following extract of a Directory Proxy Server access log file shows the start (CONNECT) and end (DISCONNECT) of a connection, conn=0. The log shows all the OPERATION requests performed by a client this connection and the related SERVER_OP requests sent to the backend server by Directory Proxy Server on behalf of the client.
[timestamp] - CONNECT - INFO - conn=0 client=129.157.192.132:59112 server=0.0.0.0:9389 protocol=LDAP [timestamp] - OPERATION - INFO - conn=0 op=0 BIND dn="uid=u1,ou=users,o=movie" method="SIMPLE" [timestamp] - SERVER_OP - INFO - conn=0 op=0 BIND dn="uid=u1,ou=users,o=movie" method="SIMPLE" s_msgid=2 s_conn=server-1:1 [timestamp] - SERVER_OP - INFO - conn=0 op=0 BIND RESPONSE err=0 msg="" s_conn=server-1:1 [timestamp] - OPERATION - INFO - conn=0 op=0 BIND RESPONSE err=0 msg="" etime=0 [timestamp] - OPERATION - INFO - conn=0 op=1 msgid=2 SEARCH base="o=movie" scope=2 filter="(objectclass=*)" [timestamp] - SERVER_OP - INFO - conn=0 op=1 SEARCH base="o=movie" scope=2 filter="(objectclass=*)" s_msgid=3 s_conn=server-1:1 [timestamp] - SERVER_OP - INFO - conn=0 op=1 SEARCH RESPONSE err=0 msg="" nentries=12 s_conn=server-1:1 [timestamp] - OPERATION - INFO - conn=0 op=1 SEARCH RESPONSE err=0 msg="" nentries=12 etime=0 [timestamp] - OPERATION - INFO - conn=0 op=2 UNBIND [timestamp] - SERVER_OP - INFO - conn=0 op=-1 BIND dn="" method="SIMPLE" s_msgid=4 s_conn=server-1:1 [timestamp] - SERVER_OP - INFO - conn=0 op=-1 BIND RESPONSE err=0 msg="" s_conn=server-1:1 [timestamp] - DISCONNECT - INFO - conn=0 reason="unbind" |
Following this log, it is possible to track all operations that were performed by or on behalf of a particular client.
When Directory Proxy Server starts up, it establishes connections with all the remote servers identified in its configuration. These connections are logged in the Directory Proxy Server access log, and are identified by the field s_conn=server-name:number. The server-name is defined in the Directory Proxy Server configuration and refers to a specific backend server. The number indicates how many connections there have been to this backend server, through the same port.
For example, in the following extract from the Directory Proxy Servers_conn=server-1:1 is the first connection to remote server server-1 through port 59100.
SERVER_OP - INFO - Created connection for BIND s_conn=server-1:1 client=129.157.192.132:59100 |
When this connection is established, the corresponding line in the Directory Server access log shows that the connection from Directory Proxy Server through port 59100 is identified with the connection ID conn=244.
conn=244 op=-1 msgId=-1 - fd=19 slot=19 LDAP connection from 129.157.192.132:59100 to 129.157.192.132 |
For the remainder of the life of this connection, server-1:1 in the Directory Proxy Server can be mapped to conn=24 in the Directory Server access log.
This kind of mapping between connections also requires that Directory Proxy Server and the backend Directory Server are synchronized.
Note that a connection from Directory Proxy Server to a backend Directory Server can remain alive for several days. If you rotate logs, either manually or automatically, it might therefore be necessary to access archived log files to trace the operations performed during a connection.
A client is identified in the access logs by its IP address and, optionally, by its bind DN. When a client establishes a connection to Directory Proxy Server, the following kind of message is logged in the Directory Proxy Server access log:
[timestamp] - CONNECT - INFO - conn=0 client=IP1:port1 server=IP2:port2 protocol=LDAP |
Directory Proxy Server identifies this client connection as conn=0.
When Directory Proxy Server establishes a connection with a remote Directory Server, the following kind of message is logged in the Directory Proxy Server access log:
[timestamp] - SERVER_OP - INFO - Created connection for READ s_conn=server-1:1 client=IP2:port3 server=IP4:port4 protocol=LDAP main |
Directory Proxy Server identifies this connection to the remote server as s_conn=server-1:1.
At the same time, the following kind of message is logged in the Directory Server access log:
[timestamp] conn=13 op=-1 msgId=-1 - fd=23 slot=23 LDAP connection from IP2:port3 to IP4 |
So, Directory Server identifies the connection as conn=13.
Tracking the connection in this way enables you to identify the full connection path from the client to Directory Server.
Directory Proxy Server does not wait for a client connection before it establishes a connection to a remote server. The Directory Proxy Server configuration specifies that certain connections are dedicated to bind operations, others to read operations, and others to write operations. When Directory Proxy Server starts up, it establishes all connections to the remote servers, according to this configuration.
When a connection has been established completely (from the client to Directory Server) the client can be identified by its DN.
Directory Server recognizes the client DN as one of the following:
True client bind DN. The bind DN is the client's own bind DN if Directory Proxy Server is configured in Use Bind mode.
Modified client bind DN. The bind DN is modified if Directory Proxy Server is configured in User Proxy Auth Control mode. The DN is modified as a result of DN renaming or user mapping.
A single connection can be used by multiple clients (though not simultaneously). To identify a client connection correctly in the access logs, Directory Proxy Server and Directory Server must be synchronized, that is, the server clock must be as close as possible. This will ensure that the timestamps in the access logs correspond. If the servers are not synchronized, you should synchronize them by using a time server, or evaluate the difference between the server clocks and search the access logs taking this difference into account.