Activity logging

The LDAP server supports logging client activity in an activity log file. The activity log file can be analyzed for LDAP server load analysis to determine the client operations that are handled by the server. The activity log records can contain information about operations that are handled by the server, client IP addresses, messages that are generated by the server, and hourly activity summary statistics. The LDAP server activity logging support has a number of features that allow the LDAP root administrator to customize the client activity to be logged.

The available versions of activity logging are version 0 and version 1. Activity log version 1 is the enhanced activity logging version. It includes more features to help debug DAP issues and inappropriate user operations of the LDAP server in addition to all features in version 0. For example, the addition of logging attributes in the add and modify requests allows you to detect when and who modified the critical attributes. The connect and disconnect records allow the detection of software configuration errors or denial of service attacks. The abandon record shows when a request is abandoned and the msgid of the request that is abandoned.

Start of changeThe activity logging function has two logging modes, synchronous mode and asynchronous mode.
  • In synchronous mode, the log records are immediately written to file during client activities. Because each worker thread will write logs to file during requests handling, thread contention might be excessive, especially during high currency situations.
  • In asynchronous mode, the resource contention can be relieved by using logging cache mechanism. Log records are stored in cache temporarily and are periodically written to file. Asynchronous mode can be enabled when the logFileSync configuration option is configured with a nonzero value. That value represents the number of seconds that the LDAP server waits before next writing. When logFileSync is configured with a value of 0, the synchronous mode is enabled.

    The asynchronous mode has a constraint. When LDAP server abends or stops abnormally, if there are records in cache that are not written to file yet, these records might be lost.

End of change
The features for version 0 include the following ones:
  • Logging the start or end of a client operation.
  • Logging only client update operations (add, delete, modify, extended operations, and modifydn).
  • Logging all client operations (add, bind, compare, delete, extended operations, modify, modifydn, search, and unbind).
  • Logging messages that are generated by the server.
  • Logging hourly client activity summary statistics.
  • Logging only requests from certain client IP addresses.
  • Activity log file archiving or rollover that copies the current activity log file to another location for load analysis.
The features for version 1 include:
  • Logging the start or end of a client operation.
  • Logging only client update operations (add, delete, modify, extended operations, and modifydn).
  • Logging all client operations (add, bind, compare, delete, extended operations, modify, modifydn, search, and unbind).
  • Logging messages that are generated by the server.
  • Logging hourly client activity summary statistics.
  • Logging only requests from certain client IP addresses.
  • Activity log file archiving or rollover that copies the current activity log file to another location for load analysis.
  • A configuration keyword that enables the new version, thus users that want the previous behavior are not affected.
  • Logging the start and end of a connection.
  • Logging abandon requests.
  • Adding the msgid to requests that can be abandoned so that abandon requests can be matched to the requests they affect. The requests include: add, bind, compare, delete, exop, modify, rename, and search.
  • Logging the attribute names in the add request records.
  • Logging the attribute names and an indication of the attribute being added, deleted, or replaced in the modify request records.
  • Logging requests unknown to the activity log.

Start and end connection logging

The following is an example of version 1 merged activity log records containing connection start and connection end messages:
Thu Oct 8 08:37:59 2009 mergedRecord Connect: connid = 1374, clientIP = 1.2.3.4, 
 listen = ldap://[fe00::f4f7:0:0:7442:7510]:389
Thu Oct 8 08:50:59 2009 mergedRecord Disconnect: connid = 1374, clientIP = 1.2.3.4, 
 bind = 'cn=john', cause = 1
The following is an example of version 1 non-merged activity log records containing connection start and connection end messages:
Thu Oct 8 08:43:43.424715 2009 Connect: connid = 1, listen = 
 ldap://[fe00::f4f7:0:0:7442:7510]:389, IP = 1.2.3.4,
Thu Oct 8 08:49:45.424716 2009 Disconnect: connid = 1, DN = 'cn=john', cause = 1, 
 IP = 1.2.3.4

Abandon request

The following is an example of a version 1 merged activity log record for an abandon request:
Thu Oct 8 08:37:59 2009 mergedRecord Abandon : connid = 1374, 
 clientIP = 9.12.47.67, time = 711usec, msgid = 123, targetmsgid = 456
The following is an example of version 1 non-merged activity log records for an abandon request:
Thu Oct 8 08:43:43.424715 2009 Abandon: connid = 1, msgid = 123, targetmsgid = 456, 
 IP = 1.2.3.4
Thu Oct 8 08:49:45.424716 2009 End Abandon: connid = 1, msgid = 123, 
 targetmsgid = 456, IP = 1.2.3.4

Attribute names in add request records

Attribute names is a string of attribute names that are separated by spaces. The following is an example of a version 1 merged activity log record for an add request:
Thu Oct 8 08:37:59 2009 mergedRecord Add: connid = 1374, clientIP = 1.2.3.4, 
 bind = 'cn=john,ou=zos,o=ibm,c=us', rc = 0, time = 49268usec, 
 controls = 1.3.6.1.4.1.42.2.27.8.5.1, target = ou=zos,o=ibm,c=us, msgid = 789, 
 attrs = cn objectclass description, rsn = NA
The following is an example of a version 1 non-merged activity log record for an add request:
Thu Oct 8 08:43:43.424715 2009 Add: connid = 1, DN = 'cn=john,ou=zos,o=ibm,c=us', msgid = 789, 
 IP = 1.2.3.4
Thu Oct 8 08:49:45.424716 2009 End Add: connid = 1, DN = cn=john,ou=zos,o=ibm,c=us, rc = 0, 
 msgid = 789, attrs = cn objectclass description, IP = 1.2.3.4

Attribute names in modify request records

Version 1 of activity logging provides attribute names and an indication of the attribute being added, deleted, or replaced in the modify request records.

Attribute names in a modify request record is a string with an indication of:
  • the action taken separated by spaces, ended by a comma.
  • "-" indicates that the attribute is deleted.
  • "+" indicates that the attribute is added.
  • "!" indicates that the attribute is replaced.
The following is an example of a version 1 merged activity log record for a modify request:
Thu Oct 8 08:37:59 2009 mergedRecord Modify: connid = 1374, clientIP = 1.2.3.4, 
 bind = 'cn=john,ou=zos,o=ibm,c=us', rc = 0, time = 49268usec, 
 controls = 1.3.6.1.4.1.42.2.27.8.5.1, target = 'ou=zos,o=ibm,c=us', msgid = 789, 
 attrs = -telephone +mobilephone !socsecuritynumber, rsn = NA
The following is an example of a version 1 non-merged activity log record for a modify request:
Thu Oct 8 08:43:43.424715 2009 Modify: connid = 1, DN = 'cn=john,ou=zos,o=ibm,c=us', msgid = 789, 
 IP = 1.2.3.4
Thu Oct 8 08:49:45.424716 2009 End Modify: connid = 1, 
 DN = 'cn=john,ou=zos,o=ibm,c=us', rc = 0, msgid = 789, attrs = -telephone +mobilephone 
 !socsecuritynumber, IP = 1.2.3.4

Logging requests unknown to activity logging

The following is an example of a version 1 merged activity log record for an unknown request:
Thu Oct 8 08:37:59.424715 2009 mergedRecord Unknown: type = 25, connid = 1, clientIP = 9.12.47.67, 
 bind = 'cn=Admin', rc = 0, time = 711usec, controls = , msgid = 2, rsn = NA
The following is an example of a version 1 non-merged activity log record for an unknown request:
Tue Oct 9 02:16:23.822710 2009 Unknown: type = 25, connid = 1, msgid = 2, IP = 9.12.47.67
Tue Oct  9 02:16:23.822789 2009 End Unknown: type = 25, connid = 1,  msgid = 2, IP = 9.12.47.67

Configuring the activity log support

The logfile configuration option in the global section of the LDAP server configuration file specifies the location of the z/OS® UNIX System Services file or data set where activity log records are written. If a z/OS UNIX System Services file is specified for the logfile configuration option, a fully qualified name must be specified. You should use a sequential data set if you want to use data set for the activity log file. If you must use a partitioned data set, make sure that the record length of the data set is large enough to contain all possible activity log records. Otherwise, the LDAP server fails to write the specific activity log record and the activity log is disabled.

Note: Start of changeFor synchronous mode,End of change MVS multi-volume data sets or potential multi-volume data sets (those with Dynamic Volume Count) cannot be used for the activity log file. Similarly, GDG data sets are allowed to be used for activity logs, but they cannot be multivolume or potential multivolume data sets. An error message is produced if an attempt is made to roll over the activity log is rolled to a new GDG data set if it was created as multivolume. For example,
GLD1221E Unable to write to file //'LDAP.ACTLOG.': 24/C0200011 - EDC5024I
An attempt is made to close a file that is opened on another thread

Start of changeBut for asynchronous mode, MVS multi-volume data sets or potential multi-volume data sets are supported.End of change

The following code is an example of a logfile configuration option that specifies a z/OS UNIX System Services file:
logfile /etc/ldap/ldap.activity.log
If the logfile configuration option is not specified, the default location of the activity log file is /etc/ldap/gldlog.output. A partitioned or sequential data set can be specified in the logfile configuration option by using a DDNAME JCL card or as a specific data set. If a data set is to be used for the activity log, create it before it is used because the LDAP server uses system defaults to create the data set. Those system defaults might not be correct for the activity log. If a GDG (Generated Data Group) data set is used for the activity log, the GDG base must be specified for the logfile configuration option. The base must also be created before the server is started. The following sample JCL creates a base GDG named GLD.GDGBASE that might contain up to three generated data sets.
Figure 1. GDG JCL example
//STEP1     EXEC PGM=IDCAMS
//SYSPRINT  DD SYSOUT=*
//SYSIN     DD *
	 DEFINE GDG(		-
	    NAME(GLD.GDGBASE)     -
	    LIMIT(3)		-
		  NOEMPTY		-
		  SCRATCH)
/*
//  

You do not need to create a model GDG because the LDAP server ignores any model that is associated with the activity log's GDG when new generation data sets are created. The LDAP server uses the Storage Management Subsystem (SMS) defaults for that high-level qualifier when it creates the generation data sets. See Configuration file options for more information about the logfile configuration option.

The following are examples of specifying data sets for the activity log file:
logfile //DD:LOGOUT
logfile //'GLD.ACTLOG'
logfile //'GLD.MYLOG(OUT)'
logfile //'GLD.GDGBASE'
The LDAP server supports automatic activity log file rollover or archiving based on the time of day or the size of the log file. The activity log archiving is only supported when the log file is a z/OS UNIX System Services file or a GDG (Generated Data Group) data set. When the logFileRolloverTOD configuration option has a value between 00:00 and 23:59, it indicates the time each day when the current activity log file is archived. See Configuration file options for more information about the logFileRolloverTOD configuration option. When the logFileRolloverSize configuration option has a nonzero size, it indicates the size in bytes, megabytes, kilobytes, or gigabytes that the activity log file is required to have before it is archived or rolled over. See Configuration file options for more information about the logFileRolloverSize configuration option. When the activity log file reaches one of these thresholds or is manually rolled over with the LOG server operator modify command, the following occurs if the log file is a z/OS UNIX file:
  • The current activity log file is renamed with the current Coordinated Universal Time stamp that is appended to the end of the file name.
  • If the logFileRolloverDirectory configuration option is specified, the archived log file is moved to that directory. Otherwise, the archived activity log file is left in the same directory as the current activity log file. Use activity log archiving or rollover only when the underlying z/OS UNIX file system is the same between the directory in the specified logfile configuration option and the directory that is specified in the logFileRolloverDirectory. For more information about the logFileRolloverDirectory configuration option, see Configuration file options.
  • After the archiving completes, the server opens a new activity log file with the name that is specified in the logfile configuration option.
When archiving by using data sets, specify the same Generated Data Group (GDG) base name for both the logfile and logFileRolloverDirectory configuration options. When logging is first activated, a new data set generation in the GDG is created and log records are written to that data set. Each time rollover or archiving occurs, the current activity log file is closed, and a new data set generation is used.
Note: When archiving using a GDG, no more than 255 new data set generations can be created during the life of the server. If the limit is exceeded, the old generations are reused and the log data is overwritten. To avoid exceeding this limit, you should plan the rollover strategy and data set capacity. Alternatives include:
  • Archive once per day by using logFileRolloverTOD, if your server is restarted more often than every 255 days. Ensure the data set allocations accommodate a full day's worth of activity log records.
  • Archive based on data set size, make the logFileRolloverSize large enough such that 255 generations do not occur before the server is restarted. Ensure that the data set allocations accommodate the size that is chosen.
  • Consider logging and archiving using z/OS UNIX System Services files instead because they are not constrained by this limitation.
Activity log file rollover or archiving is not supported when the logfile or logFileRolloverDirectory configuration options specify a partitioned data set, sequential data set, or a DD card.
When the activity log is configured to log client operations and is active, the LDAP server logs all client operations from all IP addresses. However, the activity log can be configured to include or exclude client operations from certain IP addresses by using the logFileFilter configuration option or the LOG operator modify command. See Configuration file options for more information about the logFileFilter configuration option. An IETF RFC 2254 compliant LDAP search filter can be specified in the logFileFilter configuration option or the LOG operator modify command using only the ibm-filterIP attribute type in the filters. The following example logFileFilter configuration option specifies to only log client operations from IP addresses starting with 1.2.3* or 1.2.4*.
logFileFilter (|(ibm-filterIP=1.2.3*)(ibm-filterIP=1.2.4*))

The default data collection setting is to collect no data in the activity log. The default is modified by environment variables or through the usage of the LDAP server LOG operator modify command. The environment variables are read as the server starts when the LOG operator modify command can be specified after the server has started. You can use the LOG operator modify command to modify the logFileFilter configuration option.

To enable the version 1 features of the activity log, specify the logFileVersion configuration option in the configuration file, with the value of 1. For more information about how to configure the version, see Configuration file options for the logFileVersion configuration option.

An operator modify command can be sent to the LDAP server from the SDSF or the operator’s console. Note if the command is entered from SDSF, it must be preceded by a slash (/). The format of the LDAP server LOG operator modify command is:
F DSSRV, LOG { WRITEOPS | ALLOPS | SUMMARY | TIME | NOTIME | MERGEDRECORD | MSGS |
 NOMSGS | FLUSH | STOP | ROLLOVER | FILTER,filter }
where one of the options in the { } must be specified. No more than one option in the { } is allowed to be specified at a time on the LOG operator modify command and the { } should not be specified as part of the command.
If the activity log must be restarted with logging the beginning and end of all operations, specify the following LOG operator modify commands:
  F DSSRV, LOG ALLOPS
then,
 F DSSRV, LOG TIME

The logFileOps configuration option and the LOG operator modify command can be used to control which operations generate log records. Before specifying an operation setting, no operation logging is performed. For more information, see the logFileOps configuration option in Configuration file options.

Summary records are created on an hourly basis, when rollover or archiving occurs, or when an LDAP server LOG operator modify command is processed.
Note: If activity logging is not active, summary records are not created.

The summary log records contain information about the operations that the server has processed.

Following is an example of the summary log records:
Tue Jun 15 14:26:43.785091 2010 total operations started = 113780
Tue Jun 15 14:26:43.785165 2010 total operations completed = 113780
Tue Jun 15 14:26:43.785185 2010 total binds completed = 31926
Tue Jun 15 14:26:43.785202 2010 total unbinds completed = 31925
Tue Jun 15 14:26:43.785221 2010 total searches completed = 17092
Tue Jun 15 14:26:43.785238 2010 total modifies completed = 14058
Tue Jun 15 14:26:43.785254 2010 total adds completed = 7013
Tue Jun 15 14:26:43.785270 2010 total deletes completed = 7013
Tue Jun 15 14:26:43.785286 2010 total modifydns completed = 1290
Tue Jun 15 14:26:43.785302 2010 total compares completed = 133
Tue Jun 15 14:26:43.785318 2010 total abandons completed = 0
Tue Jun 15 14:26:43.785334 2010 total extendedops completed = 3330
Tue Jun 15 14:26:43.785349 2010 total unknown completed = 0
Tue Jun 15 14:26:43.785355 2010 total group gatherings completed = 98876
Tue Jun 15 14:26:43.785366 2010 total search entries sent = 332904
Tue Jun 15 14:26:43.785381 2010 total bytes sent = 83800442
Tue Jun 15 14:26:43.785396 2010 total search references sent = 0
Tue Jun 15 14:26:43.785411 2010 total search pages sent = 1688
Tue Jun 15 14:26:43.785427 2010 total paged searches completed = 844
Tue Jun 15 14:26:43.785445 2010 total sorted searches completed = 3423
Tue Jun 15 14:26:43.785459 2010 total connections processed = 31926
Tue Jun 15 14:26:43.785476 2010 current connections = 0
Tue Jun 15 14:26:43.785491 2010 connection high water mark = 2
Tue Jun 15 14:26:43.785506 2010 connections timed out = 0
Tue Jun 15 14:26:43.785521 2010 paged result sets timed out = 0

The logFileRecordType configuration option and the LOG operator modify command can be used to control when log records are generated. For more information, see the logFileRecordType configuration option at Configuration file options.

The following are examples of activity log records containing start and end records:
Thu Oct  8 07:41:08 2009 Bind SIMPLE: connid = A, DN = cn=john,ou=zos,o=ibm,c=us, IP = 1.2.3.4
Thu Oct  8 07:41:08 2009 End Bind SIMPLE: connid = A, DN = cn=john,ou=zos,o=ibm,c=us, safid = , rc = 0, 
 IP = 1.2.3.4, policyUpdated = T
Thu Oct 8 07:41:08 2009 Search: connid = A, base = ou=zos,o=ibm,c=us, filter = (objectclass=*), scope = 2, 
 attrs = , IP = 1.2.3.4, searchFlags = 0
Thu Oct  8 07:41:08 2009 End Search: connid = A, base = ou=zos,o=ibm,c=us, filter = (objectclass=*), scope = 2, 
 count = 4, rc = 0, IP = 1.2.3.4, searchFlags = 0
Thu Oct  8 07:41:08 2009 Unbind: connid = A, DN = cn=john,ou=zos,o=ibm,c=us, IP = 1.2.3.4
Thu Oct  8 07:41:08 2009 End Unbind: connid = A, DN = cn=john,ou=zos,o=ibm,c=us, IP = 1.2.3.4
The following are examples of activity log records merged records:
Thu Oct  8 08:37:59 2009 mergedRecord Bind: connid = 1374, clientIP = 1.2.3.4, bind = cn=john,ou=zos,o=ibm,c=us, 
 rc = 0, time = 49268usec, controls = 1.3.6.1.4.1.42.2.27.8.5.1, listen = ldap://
 [fe00::f4f7:0:0:7442:7510]:389, seclabel = , mech = SIMPLE, saf = , policyUpdated = T, rsn=NA
Thu Oct  8 08:37:59 2009 mergedRecord Search: connid = 1374, clientIP = 1.2.3.4, bind = cn=john,ou=zos,o=ibm,c=us, 
 rc = 0, time = 1437usec, controls = , target = ou=zos,o=ibm,c=us, filter = (objectclass=*), scope = 2, attrs = , 
 count = 4, searchFlags = 0, rsn=NA
Thu Oct  8 08:37:59 2009 mergedRecord Unbind: connid = 1374, clientIP = 1.2.3.4, bind = cn=john,ou=zos,o=ibm,c=us, 
 rc = 0, time = 6usec, controls = , listen = ldap://[fe00::f4f7:0:0:7442:7510]:389, seclabel = , saf = , rsn=NA
See Activity log records for a description of the different fields that are present in activity log records.
Note: When the client connects to the LDAP server over the PC interface, the IP address is reported as PC. If a request is handled by the cross-system facility (XCF), the IP address is reported as XCF.

The logFileMicroseconds configuration option controls if all generated log records contain microseconds in their time stamps. You cannot use the LOG operator modify command to modify this section. The default does not include microseconds in the time stamps. For more information, see the logFileMicroseconds configuration option at Configuration file options.

The following examples show activity log records that contain microseconds:
Thu Oct  8 08:43:43.424715 2009 Bind SIMPLE: connid = 1, DN = cn=tom,ou=zos,o=ibm,c=us, IP = 1.2.3.4
Thu Oct  8 08:43:43.455011 2009 End Bind SIMPLE: connid = 1, DN =  cn=tom,ou=zos,o=ibm,c=us, safid = , rc = 0, IP = 1.2.3.4, 
 policyUpdated = F
Thu Oct  8 08:43:43.466558 2009 Search: connid = 1, base = cn=tom,ou=zos,o=ibm,c=us, filter = (objectclass=*), scope = 2, 
 attrs = , IP = 1.2.3.4, searchFlags = 0
Thu Oct  8 08:43:43.471836 2009 End Search: connid = 1, base = cn=tom,ou=zos,o=ibm,c=us, filter = (objectclass=*), scope = 2, 
 count = 1, rc = 0, IP = 1.2.3.4, searchFlags = 0
Thu Oct  8 08:43:43.478053 2009 Unbind: connid = 1, DN = cn=tom,ou=zos,o=ibm,c=us, IP = 1.2.3.4
Thu Oct  8 08:43:43.478181 2009 End Unbind: connid = 1, DN = cn=tom,ou=zos,o=ibm,c=us, IP = 1.2.3.4

The logFileMsgs configuration option and the LOG operator modify command can be used to control if log records are generated when messages are created by the LDAP server. For more information, see the logFileMsgs configuration option at Configuration file options.

The following example shows an activity log record containing a message:
Thu Oct  8 08:43:24.748429 2009 GLD1059I Listening for requests on 127.0.0.1 port 389.
To update the activity log filter that is specified in the logFileFilter configuration option, issue a LOG operator modify command. The following command updates the server to only log client requests originating from IP address 1.2.4.5.
F DSSRV, LOG FILTER,(IBM-FILTERIP=1.2.4.5)
The current activity log can be manually rolled over or archived by using the process described earlier in this section by issuing the following LOG operator modify command:
F DSSRV, LOG ROLLOVER
As the log records are produced, some buffering of the output is performed by the system. The buffers are flushed before the server shuts down. However, you can force the server to flush the buffers by issuing the following LOG operator modify command:
F DSSRV, LOG FLUSH
To have the server stop collecting activity data, issue the following LOG operator modify command:
F DSSRV, LOG STOP
To restart activity logging, specify a LOG operator modify command with a new setting.
F DSSRV, LOG ALLOPS
To query the current activity log settings, issue the following DISPLAY operator modify command:Start of change
F DSSRV,DISPLAY LOG

GLD1290I Activity log status
Option:          Setting
LOGGING          YES
FILE NAME        /etc/ldap/gldlog.output
FILE SYNC        NO
ROLLOVER         YES
ROLLOVER DIR     N/A
ROLLOVER SIZE    10K
ROLLOVER TOD     N/A
LOG VERSION      0
LOG FILTER       N/A
LOG OPERATION    ALL
LOG TIME         YES
LOG MESSAGE      NO
LOG MICROSECOND  NO
End of change