Introduction

Directory Server Enterprise Edition (DSEE) can provide the administrator some very useful information in the access logs around timing. In particular, the etimes can provide some insight into how the directory is performing the internal operations. The dseeEtimes.pl script will provide the user a histogram report of all the etimes and counts providing a visual representation of operation performance.

This is in addition to what is available from other performance tools such as SLAMD . In those tools, most of the results are averages, where this script will provide the actual etimes of the directory operations. It is important to note that etimes in the directory server represent the elapsed etime during the operation internal to the directory server. It doesn't include network or potential queuing time that other tools would help measure.

Note: Sun provides no support for use of the dseeEtimes.pl utility. In addition, this utility is not available in the packaged DSEE bits available from Sun. dseeEtimes.pl is only available from right here, or your friendly neighborhood directory expert.

Background

When a directory access log is created for a search operation, it will create a record similar to:

 ...
[10/Mar/2007:14:15:24 -0600] conn=69 op=16977 msgId=16978 - SRCH base="ou=people,o=example,o=example.com" scope=2 filter="(uid=1000735830)" attrs="1.1"
[10/Mar/2007:14:15:24 -0600] conn=69 op=16977 msgId=16978 - RESULT err=0 tag=101 nentries=1 etime=0.094
 ...

The RESULT for the SRCH operation took roughly 94ms to complete it's internal directory search logic. It doesn't include the roundtrip, end-to-end, total elapsed time. Depending on network, cpu load and locks, the actual time may be much larger. However, during high performance benchmark testing, where these other factors are minimized, the etime can provide a fairly accurate representation of the performance of directory server.

Downloads

• Version 1.1 dseeEtimes.tar.gz

dseeEtimes.pl Sample Report

A sample report for this script might look like:

TITLE     : Sample Report of Search eTimes
RUN       : 2-2-108
LOGDIR    : /ds/ds6/logs
TAG       : Search
UNIT      : ms
        0 :       219
        1 :   2876242
        2 :    476686
        3 :     48966
        4 :     13722
        5 :     12722
        6 :     14794
        7 :     16429
        8 :     16340
        9 :     11449
       10 :      5142
---- cut data for sample purposes ----

This report shows the histogram of etimes in an access log. It shows for example that 219 resulted in less than a ms of time, 2,876,242 resulted in an etime between 1 and 2 ms, and so on.

Running dseeEtimes.pl

To run, just download dseeEtimes.pl and run it using the following usage:

  Usage: ./dseeEtimes.pl -t <title> -o <op> -u <unit> -l <logfiles directory location>
Version: 1.1 (3/1/08)

      title : Title of Report
    log dir : Location of Access Logs with etimes
                Will process all files in this directory starting with name 'access'
       unit : Time Unit of Each eTime 
                sec = seconds <default>
                ms = milliseconds
         op : LDAP Tag or Operation
                 97 Bind
                101 Search
                103 Modify
                105 Add
                107 Delete
                109 ModifyDN
                111 Compare
                120 Extended Op

dseeEtimeAnalysisSample.ods (Spreadsheet)

Included with the download is an OpenOffice Speradsheet (.ods) that will display and analyze the results from the dseeEtimes.pl reports. A screen shot of the sample page is:

This spreadsheet is offered as an example. Note that you can import many reports into one worksheet and the Summary sheet will provide an overall view of all the reports. The numbers to the right depict the % of transactions with eTimes within certain ranges (denoted by the headings (10, 100, 500, 1000, 2000, 5000). These headings in this example are based on milliseconds (ms).

Additional Notes

• dseeEtimes.pl - No support by Sun
• Depending on size of access logs, it may take some time to process.
• Recommend sending output of command to a sample.report file and putting in background.
• Tip: Run on a small accesslog to ensure that it's running fine