001    /*
002     * Copyright 2009-2015 UnboundID Corp.
003     * All Rights Reserved.
004     */
005    /*
006     * Copyright (C) 2015 UnboundID Corp.
007     *
008     * This program is free software; you can redistribute it and/or modify
009     * it under the terms of the GNU General Public License (GPLv2 only)
010     * or the terms of the GNU Lesser General Public License (LGPLv2.1 only)
011     * as published by the Free Software Foundation.
012     *
013     * This program is distributed in the hope that it will be useful,
014     * but WITHOUT ANY WARRANTY; without even the implied warranty of
015     * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
016     * GNU General Public License for more details.
017     *
018     * You should have received a copy of the GNU General Public License
019     * along with this program; if not, see <http://www.gnu.org/licenses>.
020     */
021    package com.unboundid.ldap.sdk.unboundidds.examples;
022    
023    
024    
025    import java.io.File;
026    import java.io.FileInputStream;
027    import java.io.InputStreamReader;
028    import java.io.IOException;
029    import java.io.OutputStream;
030    import java.io.Serializable;
031    import java.text.DecimalFormat;
032    import java.util.ArrayList;
033    import java.util.HashMap;
034    import java.util.HashSet;
035    import java.util.Iterator;
036    import java.util.LinkedHashMap;
037    import java.util.List;
038    import java.util.Map;
039    import java.util.TreeMap;
040    import java.util.concurrent.atomic.AtomicLong;
041    import java.util.zip.GZIPInputStream;
042    
043    import com.unboundid.ldap.sdk.Filter;
044    import com.unboundid.ldap.sdk.ResultCode;
045    import com.unboundid.ldap.sdk.SearchScope;
046    import com.unboundid.ldap.sdk.Version;
047    import com.unboundid.ldap.sdk.unboundidds.logs.AbandonRequestAccessLogMessage;
048    import com.unboundid.ldap.sdk.unboundidds.logs.AccessLogMessage;
049    import com.unboundid.ldap.sdk.unboundidds.logs.AccessLogReader;
050    import com.unboundid.ldap.sdk.unboundidds.logs.AddResultAccessLogMessage;
051    import com.unboundid.ldap.sdk.unboundidds.logs.BindResultAccessLogMessage;
052    import com.unboundid.ldap.sdk.unboundidds.logs.CompareResultAccessLogMessage;
053    import com.unboundid.ldap.sdk.unboundidds.logs.ConnectAccessLogMessage;
054    import com.unboundid.ldap.sdk.unboundidds.logs.DeleteResultAccessLogMessage;
055    import com.unboundid.ldap.sdk.unboundidds.logs.DisconnectAccessLogMessage;
056    import com.unboundid.ldap.sdk.unboundidds.logs.ExtendedRequestAccessLogMessage;
057    import com.unboundid.ldap.sdk.unboundidds.logs.ExtendedResultAccessLogMessage;
058    import com.unboundid.ldap.sdk.unboundidds.logs.LogException;
059    import com.unboundid.ldap.sdk.unboundidds.logs.ModifyDNResultAccessLogMessage;
060    import com.unboundid.ldap.sdk.unboundidds.logs.ModifyResultAccessLogMessage;
061    import com.unboundid.ldap.sdk.unboundidds.logs.OperationAccessLogMessage;
062    import com.unboundid.ldap.sdk.unboundidds.logs.SearchRequestAccessLogMessage;
063    import com.unboundid.ldap.sdk.unboundidds.logs.SearchResultAccessLogMessage;
064    import com.unboundid.ldap.sdk.unboundidds.logs.UnbindRequestAccessLogMessage;
065    import com.unboundid.util.CommandLineTool;
066    import com.unboundid.util.NotMutable;
067    import com.unboundid.util.ObjectPair;
068    import com.unboundid.util.ReverseComparator;
069    import com.unboundid.util.ThreadSafety;
070    import com.unboundid.util.ThreadSafetyLevel;
071    import com.unboundid.util.args.ArgumentException;
072    import com.unboundid.util.args.ArgumentParser;
073    import com.unboundid.util.args.BooleanArgument;
074    
075    import static com.unboundid.util.StaticUtils.*;
076    
077    
078    
079    /**
080     * <BLOCKQUOTE>
081     *   <B>NOTE:</B>  This class is part of the Commercial Edition of the UnboundID
082     *   LDAP SDK for Java.  It is not available for use in applications that
083     *   include only the Standard Edition of the LDAP SDK, and is not supported for
084     *   use in conjunction with non-UnboundID products.
085     * </BLOCKQUOTE>
086     * This class provides a tool that may be used to read and summarize the
087     * contents of one or more access log files from UnboundID or Alcatel-Lucent
088     * 8661 server products.  Information that will be reported includes:
089     * <UL>
090     *   <LI>The total length of time covered by the log files.</LI>
091     *   <LI>The number of connections established and disconnected, the addresses
092     *       of the most commonly-connecting clients, and the average rate of
093     *       connects and disconnects per second.</LI>
094     *   <LI>The number of operations processed, overall and by operation type,
095     *       and the average rate of operations per second.</LI>
096     *   <LI>The average duration for operations processed, overall and by operation
097     *       type.</LI>
098     *   <LI>A breakdown of operation processing times into a number of predefined
099     *       categories (less than 1ms, between 1ms and 2ms, between 2ms and 3ms,
100     *       between 3ms and 5ms, between 5ms and 10ms, between 10ms and 20ms,
101     *       between 20ms and 30ms, between 30ms and 50ms, between 50ms and 100ms,
102     *       between 100ms and 1000ms, and over 1000ms).</LI>
103     *   <LI>A breakdown of the most common result codes for each type of operation
104     *       and their relative frequencies.</LI>
105     *   <LI>The most common types of extended requests processed and their
106     *       relative frequencies.</LI>
107     *   <LI>The number of unindexed search operations processed.</LI>
108     *   <LI>A breakdown of the relative frequencies for each type of search
109     *       scope.</LI>
110     *   <LI>The most common types of search filters used for search
111     *       operations and their relative frequencies.</LI>
112     * </UL>
113     * It is designed to work with access log files using either the default log
114     * format with separate request and response messages, as well as log files
115     * in which the request and response details have been combined on the same
116     * line.  The log files to be processed should be provided as command-line
117     * arguments.
118     * <BR><BR>
119     * The APIs demonstrated by this example include:
120     * <UL>
121     *   <LI>Access log parsing (from the
122     *       {@code com.unboundid.ldap.sdk.unboundidds.logs} package)</LI>
123     *   <LI>Argument parsing (from the {@code com.unboundid.util.args}
124     *       package)</LI>
125     * </UL>
126     */
127    @NotMutable()
128    @ThreadSafety(level=ThreadSafetyLevel.NOT_THREADSAFE)
129    public final class SummarizeAccessLog
130           extends CommandLineTool
131           implements Serializable
132    {
133      /**
134       * The serial version UID for this serializable class.
135       */
136      private static final long serialVersionUID = -1211445611798245343L;
137    
138    
139    
140      // Variables used for accessing argument information.
141      private ArgumentParser  argumentParser;
142    
143      // And argument which may be used to indicate that the log files are
144      // compressed.
145      private BooleanArgument isCompressed;
146    
147      // The decimal format that will be used for this class.
148      private final DecimalFormat decimalFormat;
149    
150      // The total duration for log content, in milliseconds.
151      private long logDurationMillis;
152    
153      // The total processing time for each type of operation.
154      private double addProcessingDuration;
155      private double bindProcessingDuration;
156      private double compareProcessingDuration;
157      private double deleteProcessingDuration;
158      private double extendedProcessingDuration;
159      private double modifyProcessingDuration;
160      private double modifyDNProcessingDuration;
161      private double searchProcessingDuration;
162    
163      // A variable used for counting the number of messages of each type.
164      private long numAbandons;
165      private long numAdds;
166      private long numBinds;
167      private long numCompares;
168      private long numConnects;
169      private long numDeletes;
170      private long numDisconnects;
171      private long numExtended;
172      private long numModifies;
173      private long numModifyDNs;
174      private long numNonBaseSearches;
175      private long numSearches;
176      private long numUnbinds;
177    
178      // The number of operations of each type that accessed uncached data.
179      private long numUncachedAdds;
180      private long numUncachedBinds;
181      private long numUncachedCompares;
182      private long numUncachedDeletes;
183      private long numUncachedExtended;
184      private long numUncachedModifies;
185      private long numUncachedModifyDNs;
186      private long numUncachedSearches;
187    
188      // The number of unindexed searches processed within the server.
189      private long numUnindexedAttempts;
190      private long numUnindexedFailed;
191      private long numUnindexedSuccessful;
192    
193      // Variables used for maintaining counts for common types of information.
194      private final HashMap<Long,AtomicLong> searchEntryCounts;
195      private final HashMap<ResultCode,AtomicLong> addResultCodes;
196      private final HashMap<ResultCode,AtomicLong> bindResultCodes;
197      private final HashMap<ResultCode,AtomicLong> compareResultCodes;
198      private final HashMap<ResultCode,AtomicLong> deleteResultCodes;
199      private final HashMap<ResultCode,AtomicLong> extendedResultCodes;
200      private final HashMap<ResultCode,AtomicLong> modifyResultCodes;
201      private final HashMap<ResultCode,AtomicLong> modifyDNResultCodes;
202      private final HashMap<ResultCode,AtomicLong> searchResultCodes;
203      private final HashMap<SearchScope,AtomicLong> searchScopes;
204      private final HashMap<String,AtomicLong> clientAddresses;
205      private final HashMap<String,AtomicLong> clientConnectionPolicies;
206      private final HashMap<String,AtomicLong> disconnectReasons;
207      private final HashMap<String,AtomicLong> extendedOperations;
208      private final HashMap<String,AtomicLong> filterTypes;
209      private final HashSet<String> processedRequests;
210      private final LinkedHashMap<Long,AtomicLong> addProcessingTimes;
211      private final LinkedHashMap<Long,AtomicLong> bindProcessingTimes;
212      private final LinkedHashMap<Long,AtomicLong> compareProcessingTimes;
213      private final LinkedHashMap<Long,AtomicLong> deleteProcessingTimes;
214      private final LinkedHashMap<Long,AtomicLong> extendedProcessingTimes;
215      private final LinkedHashMap<Long,AtomicLong> modifyProcessingTimes;
216      private final LinkedHashMap<Long,AtomicLong> modifyDNProcessingTimes;
217      private final LinkedHashMap<Long,AtomicLong> searchProcessingTimes;
218    
219    
220    
221      /**
222       * Parse the provided command line arguments and perform the appropriate
223       * processing.
224       *
225       * @param  args  The command line arguments provided to this program.
226       */
227      public static void main(final String[] args)
228      {
229        final ResultCode resultCode = main(args, System.out, System.err);
230        if (resultCode != ResultCode.SUCCESS)
231        {
232          System.exit(resultCode.intValue());
233        }
234      }
235    
236    
237    
238      /**
239       * Parse the provided command line arguments and perform the appropriate
240       * processing.
241       *
242       * @param  args       The command line arguments provided to this program.
243       * @param  outStream  The output stream to which standard out should be
244       *                    written.  It may be {@code null} if output should be
245       *                    suppressed.
246       * @param  errStream  The output stream to which standard error should be
247       *                    written.  It may be {@code null} if error messages
248       *                    should be suppressed.
249       *
250       * @return  A result code indicating whether the processing was successful.
251       */
252      public static ResultCode main(final String[] args,
253                                    final OutputStream outStream,
254                                    final OutputStream errStream)
255      {
256        final SummarizeAccessLog summarizer =
257             new SummarizeAccessLog(outStream, errStream);
258        return summarizer.runTool(args);
259      }
260    
261    
262    
263      /**
264       * Creates a new instance of this tool.
265       *
266       * @param  outStream  The output stream to which standard out should be
267       *                    written.  It may be {@code null} if output should be
268       *                    suppressed.
269       * @param  errStream  The output stream to which standard error should be
270       *                    written.  It may be {@code null} if error messages
271       *                    should be suppressed.
272       */
273      public SummarizeAccessLog(final OutputStream outStream,
274                                final OutputStream errStream)
275      {
276        super(outStream, errStream);
277    
278        decimalFormat = new DecimalFormat("0.000");
279    
280        logDurationMillis = 0L;
281    
282        addProcessingDuration      = 0.0;
283        bindProcessingDuration     = 0.0;
284        compareProcessingDuration  = 0.0;
285        deleteProcessingDuration   = 0.0;
286        extendedProcessingDuration = 0.0;
287        modifyProcessingDuration   = 0.0;
288        modifyDNProcessingDuration = 0.0;
289        searchProcessingDuration   = 0.0;
290    
291        numAbandons        = 0L;
292        numAdds            = 0L;
293        numBinds           = 0L;
294        numCompares        = 0L;
295        numConnects        = 0L;
296        numDeletes         = 0L;
297        numDisconnects     = 0L;
298        numExtended        = 0L;
299        numModifies        = 0L;
300        numModifyDNs       = 0L;
301        numNonBaseSearches = 0L;
302        numSearches        = 0L;
303        numUnbinds         = 0L;
304    
305        numUncachedAdds      = 0L;
306        numUncachedBinds     = 0L;
307        numUncachedCompares  = 0L;
308        numUncachedDeletes   = 0L;
309        numUncachedExtended  = 0L;
310        numUncachedModifies  = 0L;
311        numUncachedModifyDNs = 0L;
312        numUncachedSearches  = 0L;
313    
314        searchEntryCounts        = new HashMap<Long,AtomicLong>(10);
315        addResultCodes           = new HashMap<ResultCode,AtomicLong>(10);
316        bindResultCodes          = new HashMap<ResultCode,AtomicLong>(10);
317        compareResultCodes       = new HashMap<ResultCode,AtomicLong>(10);
318        deleteResultCodes        = new HashMap<ResultCode,AtomicLong>(10);
319        extendedResultCodes      = new HashMap<ResultCode,AtomicLong>(10);
320        modifyResultCodes        = new HashMap<ResultCode,AtomicLong>(10);
321        modifyDNResultCodes      = new HashMap<ResultCode,AtomicLong>(10);
322        searchResultCodes        = new HashMap<ResultCode,AtomicLong>(10);
323        searchScopes             = new HashMap<SearchScope,AtomicLong>(4);
324        clientAddresses          = new HashMap<String,AtomicLong>(100);
325        clientConnectionPolicies = new HashMap<String,AtomicLong>(100);
326        disconnectReasons        = new HashMap<String,AtomicLong>(100);
327        extendedOperations       = new HashMap<String,AtomicLong>(10);
328        filterTypes              = new HashMap<String,AtomicLong>(100);
329        processedRequests        = new HashSet<String>(100);
330        addProcessingTimes       = new LinkedHashMap<Long,AtomicLong>(11);
331        bindProcessingTimes      = new LinkedHashMap<Long,AtomicLong>(11);
332        compareProcessingTimes   = new LinkedHashMap<Long,AtomicLong>(11);
333        deleteProcessingTimes    = new LinkedHashMap<Long,AtomicLong>(11);
334        extendedProcessingTimes  = new LinkedHashMap<Long,AtomicLong>(11);
335        modifyProcessingTimes    = new LinkedHashMap<Long,AtomicLong>(11);
336        modifyDNProcessingTimes  = new LinkedHashMap<Long,AtomicLong>(11);
337        searchProcessingTimes    = new LinkedHashMap<Long,AtomicLong>(11);
338    
339        populateProcessingTimeMap(addProcessingTimes);
340        populateProcessingTimeMap(bindProcessingTimes);
341        populateProcessingTimeMap(compareProcessingTimes);
342        populateProcessingTimeMap(deleteProcessingTimes);
343        populateProcessingTimeMap(extendedProcessingTimes);
344        populateProcessingTimeMap(modifyProcessingTimes);
345        populateProcessingTimeMap(modifyDNProcessingTimes);
346        populateProcessingTimeMap(searchProcessingTimes);
347      }
348    
349    
350    
351      /**
352       * Retrieves the name for this tool.
353       *
354       * @return  The name for this tool.
355       */
356      @Override()
357      public String getToolName()
358      {
359        return "summarize-access-log";
360      }
361    
362    
363    
364      /**
365       * Retrieves the description for this tool.
366       *
367       * @return  The description for this tool.
368       */
369      @Override()
370      public String getToolDescription()
371      {
372        return "Examine one or more access log files from UnboundID or " +
373               "Alcatel-Lucent 8661 server products to display a number of " +
374               "metrics about operations processed within the server.";
375      }
376    
377    
378    
379      /**
380       * Retrieves the version string for this tool.
381       *
382       * @return  The version string for this tool.
383       */
384      @Override()
385      public String getToolVersion()
386      {
387        return Version.NUMERIC_VERSION_STRING;
388      }
389    
390    
391    
392      /**
393       * Retrieves the maximum number of unnamed trailing arguments that may be
394       * provided for this tool.
395       *
396       * @return  The maximum number of unnamed trailing arguments that may be
397       *          provided for this tool.
398       */
399      @Override()
400      public int getMaxTrailingArguments()
401      {
402        return -1;
403      }
404    
405    
406    
407      /**
408       * Retrieves a placeholder string that should be used for trailing arguments
409       * in the usage information for this tool.
410       *
411       * @return  A placeholder string that should be used for trailing arguments in
412       *          the usage information for this tool.
413       */
414      @Override()
415      public String getTrailingArgumentsPlaceholder()
416      {
417        return "{path}";
418      }
419    
420    
421    
422      /**
423       * Adds the command-line arguments supported for use with this tool to the
424       * provided argument parser.  The tool may need to retain references to the
425       * arguments (and/or the argument parser, if trailing arguments are allowed)
426       * to it in order to obtain their values for use in later processing.
427       *
428       * @param  parser  The argument parser to which the arguments are to be added.
429       *
430       * @throws  ArgumentException  If a problem occurs while adding any of the
431       *                             tool-specific arguments to the provided
432       *                             argument parser.
433       */
434      @Override()
435      public void addToolArguments(final ArgumentParser parser)
436             throws ArgumentException
437      {
438        // We need to save a reference to the argument parser so that we can get
439        // the trailing arguments later.
440        argumentParser = parser;
441    
442        // Add an argument that makes it possible to read a compressed log file.
443        final String description = "Indicates that the log file is compressed..";
444        isCompressed = new BooleanArgument('c', "isCompressed", description);
445        parser.addArgument(isCompressed);
446      }
447    
448    
449    
450      /**
451       * Performs any necessary processing that should be done to ensure that the
452       * provided set of command-line arguments were valid.  This method will be
453       * called after the basic argument parsing has been performed and immediately
454       * before the {@link CommandLineTool#doToolProcessing} method is invoked.
455       *
456       * @throws  ArgumentException  If there was a problem with the command-line
457       *                             arguments provided to this program.
458       */
459      @Override()
460      public void doExtendedArgumentValidation()
461             throws ArgumentException
462      {
463        // Make sure that at least one access log file path was provided.
464        final List<String> trailingArguments =
465             argumentParser.getTrailingArguments();
466        if ((trailingArguments == null) || trailingArguments.isEmpty())
467        {
468          throw new ArgumentException("No access log file paths were provided.");
469        }
470      }
471    
472    
473    
474      /**
475       * Performs the core set of processing for this tool.
476       *
477       * @return  A result code that indicates whether the processing completed
478       *          successfully.
479       */
480      @Override()
481      public ResultCode doToolProcessing()
482      {
483        long logLines = 0L;
484        for (final String path : argumentParser.getTrailingArguments())
485        {
486          final File f = new File(path);
487          out("Examining access log ", f.getAbsolutePath());
488          final AccessLogReader reader;
489          try
490          {
491            if (isCompressed.isPresent())
492            {
493              reader = new AccessLogReader(new InputStreamReader(
494                   new GZIPInputStream(new FileInputStream(f))));
495            }
496            else
497            {
498              reader = new AccessLogReader(f);
499            }
500          }
501          catch (IOException ioe)
502          {
503            err("Unable to open access log file ", f.getAbsolutePath(), ":  ",
504                getExceptionMessage(ioe));
505            return ResultCode.LOCAL_ERROR;
506          }
507    
508          long startTime = 0L;
509          long stopTime  = 0L;
510    
511          while (true)
512          {
513            final AccessLogMessage msg;
514            try
515            {
516              msg = reader.read();
517            }
518            catch (IOException ioe)
519            {
520              err("Error reading from access log file ", f.getAbsolutePath(),
521                  ":  ", getExceptionMessage(ioe));
522              return ResultCode.LOCAL_ERROR;
523            }
524            catch (LogException le)
525            {
526              err("Encountered an error while attempting to parse a line in" +
527                  "access log file ", f.getAbsolutePath(), ":  ",
528                  getExceptionMessage(le));
529              continue;
530            }
531    
532            if (msg == null)
533            {
534              break;
535            }
536    
537            logLines++;
538            stopTime = msg.getTimestamp().getTime();
539            if (startTime == 0L)
540            {
541              startTime = stopTime;
542            }
543    
544            switch (msg.getMessageType())
545            {
546              case CONNECT:
547                processConnect((ConnectAccessLogMessage) msg);
548                break;
549              case DISCONNECT:
550                processDisconnect((DisconnectAccessLogMessage) msg);
551                break;
552              case REQUEST:
553                switch (((OperationAccessLogMessage) msg).getOperationType())
554                {
555                  case ABANDON:
556                    processAbandonRequest((AbandonRequestAccessLogMessage) msg);
557                    break;
558                  case EXTENDED:
559                    processExtendedRequest((ExtendedRequestAccessLogMessage) msg);
560                    break;
561                  case SEARCH:
562                    processSearchRequest((SearchRequestAccessLogMessage) msg);
563                    break;
564                  case UNBIND:
565                    processUnbindRequest((UnbindRequestAccessLogMessage) msg);
566                    break;
567                }
568                break;
569              case RESULT:
570                switch (((OperationAccessLogMessage) msg).getOperationType())
571                {
572                  case ADD:
573                    processAddResult((AddResultAccessLogMessage) msg);
574                    break;
575                  case BIND:
576                    processBindResult((BindResultAccessLogMessage) msg);
577                    break;
578                  case COMPARE:
579                    processCompareResult((CompareResultAccessLogMessage) msg);
580                    break;
581                  case DELETE:
582                    processDeleteResult((DeleteResultAccessLogMessage) msg);
583                    break;
584                  case EXTENDED:
585                    processExtendedResult((ExtendedResultAccessLogMessage) msg);
586                    break;
587                  case MODIFY:
588                    processModifyResult((ModifyResultAccessLogMessage) msg);
589                    break;
590                  case MODDN:
591                    processModifyDNResult((ModifyDNResultAccessLogMessage) msg);
592                    break;
593                  case SEARCH:
594                    processSearchResult((SearchResultAccessLogMessage) msg);
595                    break;
596                }
597                break;
598    
599              case ASSURANCE_COMPLETE:
600              case CLIENT_CERTIFICATE:
601              case ENTRY_REBALANCING_REQUEST:
602              case ENTRY_REBALANCING_RESULT:
603              case FORWARD:
604              case FORWARD_FAILED:
605              case ENTRY:
606              case REFERENCE:
607              default:
608                // Nothing needs to be done for these message types.
609            }
610          }
611    
612          try
613          {
614            reader.close();
615          } catch (Exception e) {}
616          logDurationMillis += (stopTime - startTime);
617        }
618    
619    
620        final int numFiles = argumentParser.getTrailingArguments().size();
621        out();
622        out("Examined ", logLines, " lines in ", numFiles,
623            ((numFiles == 1) ? " file" : " files"),
624            " covering a total duration of ",
625            millisToHumanReadableDuration(logDurationMillis));
626    
627        out();
628    
629        final double logDurationSeconds   = logDurationMillis / 1000.0;
630        final double connectsPerSecond    = numConnects / logDurationSeconds;
631        final double disconnectsPerSecond = numDisconnects / logDurationSeconds;
632    
633        out("Total connections established:  ", numConnects, " (",
634            decimalFormat.format(connectsPerSecond), "/second)");
635        out("Total disconnects:  ", numDisconnects, " (",
636            decimalFormat.format(disconnectsPerSecond), "/second)");
637    
638        if (! clientAddresses.isEmpty())
639        {
640          out();
641          final List<ObjectPair<String,Long>> connectCounts =
642               getMostCommonElements(clientAddresses, 20);
643          out("Most common client addresses:");
644          for (final ObjectPair<String,Long> p : connectCounts)
645          {
646            final long count = p.getSecond();
647            final double percent = 100.0 * count / numConnects;
648    
649            out(p.getFirst(), ":  ", count, " (", decimalFormat.format(percent),
650                ")");
651          }
652        }
653    
654        if (! clientConnectionPolicies.isEmpty())
655        {
656          long totalCCPs = 0;
657          for (final AtomicLong l : clientConnectionPolicies.values())
658          {
659            totalCCPs += l.get();
660          }
661    
662          final List<ObjectPair<String,Long>> reasonCounts =
663               getMostCommonElements(clientConnectionPolicies, 20);
664    
665          out();
666          out("Most common client connection policies:");
667          for (final ObjectPair<String,Long> p : reasonCounts)
668          {
669            final long count = p.getSecond();
670            final double percent = 100.0 * count / totalCCPs;
671            out(p.getFirst(), ":  ", p.getSecond(), " (",
672                 decimalFormat.format(percent), "%)");
673          }
674        }
675    
676        if (! disconnectReasons.isEmpty())
677        {
678          final List<ObjectPair<String,Long>> reasonCounts =
679               getMostCommonElements(disconnectReasons, 20);
680    
681          out();
682          out("Most common disconnect reasons:");
683          for (final ObjectPair<String,Long> p : reasonCounts)
684          {
685            final long count = p.getSecond();
686            final double percent = 100.0 * count / numDisconnects;
687            out(p.getFirst(), ":  ", p.getSecond(), " (",
688                 decimalFormat.format(percent), "%)");
689          }
690        }
691    
692        final long totalOps = numAbandons + numAdds + numBinds + numCompares +
693             numDeletes + numExtended + numModifies + numModifyDNs + numSearches +
694             numUnbinds;
695        if (totalOps > 0)
696        {
697          final double percentAbandon  = 100.0 * numAbandons / totalOps;
698          final double percentAdd      = 100.0 * numAdds / totalOps;
699          final double percentBind     = 100.0 * numBinds / totalOps;
700          final double percentCompare  = 100.0 * numCompares / totalOps;
701          final double percentDelete   = 100.0 * numDeletes / totalOps;
702          final double percentExtended = 100.0 * numExtended / totalOps;
703          final double percentModify   = 100.0 * numModifies / totalOps;
704          final double percentModifyDN = 100.0 * numModifyDNs / totalOps;
705          final double percentSearch   = 100.0 * numSearches / totalOps;
706          final double percentUnbind   = 100.0 * numUnbinds / totalOps;
707    
708          final double abandonsPerSecond  = numAbandons / logDurationSeconds;
709          final double addsPerSecond      = numAdds / logDurationSeconds;
710          final double bindsPerSecond     = numBinds / logDurationSeconds;
711          final double comparesPerSecond  = numCompares / logDurationSeconds;
712          final double deletesPerSecond   = numDeletes / logDurationSeconds;
713          final double extendedPerSecond  = numExtended / logDurationSeconds;
714          final double modifiesPerSecond  = numModifies / logDurationSeconds;
715          final double modifyDNsPerSecond = numModifyDNs / logDurationSeconds;
716          final double searchesPerSecond  = numSearches / logDurationSeconds;
717          final double unbindsPerSecond   = numUnbinds / logDurationSeconds;
718    
719          out();
720          out("Total operations examined:  ", totalOps);
721          out("Abandon operations examined:  ", numAbandons, " (",
722              decimalFormat.format(percentAbandon), "%, ",
723              decimalFormat.format(abandonsPerSecond), "/second)");
724          out("Add operations examined:  ", numAdds, " (",
725              decimalFormat.format(percentAdd), "%, ",
726              decimalFormat.format(addsPerSecond), "/second)");
727          out("Bind operations examined:  ", numBinds, " (",
728              decimalFormat.format(percentBind), "%, ",
729              decimalFormat.format(bindsPerSecond), "/second)");
730          out("Compare operations examined:  ", numCompares, " (",
731              decimalFormat.format(percentCompare), "%, ",
732              decimalFormat.format(comparesPerSecond), "/second)");
733          out("Delete operations examined:  ", numDeletes, " (",
734              decimalFormat.format(percentDelete), "%, ",
735              decimalFormat.format(deletesPerSecond), "/second)");
736          out("Extended operations examined:  ", numExtended, " (",
737              decimalFormat.format(percentExtended), "%, ",
738              decimalFormat.format(extendedPerSecond), "/second)");
739          out("Modify operations examined:  ", numModifies, " (",
740              decimalFormat.format(percentModify), "%, ",
741              decimalFormat.format(modifiesPerSecond), "/second)");
742          out("Modify DN operations examined:  ", numModifyDNs, " (",
743              decimalFormat.format(percentModifyDN), "%, ",
744              decimalFormat.format(modifyDNsPerSecond), "/second)");
745          out("Search operations examined:  ", numSearches, " (",
746              decimalFormat.format(percentSearch), "%, ",
747              decimalFormat.format(searchesPerSecond), "/second)");
748          out("Unbind operations examined:  ", numUnbinds, " (",
749              decimalFormat.format(percentUnbind), "%, ",
750              decimalFormat.format(unbindsPerSecond), "/second)");
751    
752          final double totalProcessingDuration = addProcessingDuration +
753               bindProcessingDuration + compareProcessingDuration +
754               deleteProcessingDuration + extendedProcessingDuration +
755               modifyProcessingDuration + modifyDNProcessingDuration +
756               searchProcessingDuration;
757    
758          out();
759          out("Average operation processing duration:  ",
760              decimalFormat.format(totalProcessingDuration / totalOps), "ms");
761    
762          if (numAdds > 0)
763          {
764            out("Average add operation processing duration:  ",
765                decimalFormat.format(addProcessingDuration / numAdds), "ms");
766          }
767    
768          if (numBinds > 0)
769          {
770            out("Average bind operation processing duration:  ",
771                decimalFormat.format(bindProcessingDuration / numBinds), "ms");
772          }
773    
774          if (numCompares > 0)
775          {
776            out("Average compare operation processing duration:  ",
777                decimalFormat.format(compareProcessingDuration / numCompares),
778                "ms");
779          }
780    
781          if (numDeletes > 0)
782          {
783            out("Average delete operation processing duration:  ",
784                decimalFormat.format(deleteProcessingDuration / numDeletes), "ms");
785          }
786    
787          if (numExtended > 0)
788          {
789            out("Average extended operation processing duration:  ",
790                decimalFormat.format(extendedProcessingDuration / numExtended),
791                "ms");
792          }
793    
794          if (numModifies > 0)
795          {
796            out("Average modify operation processing duration:  ",
797                decimalFormat.format(modifyProcessingDuration / numModifies), "ms");
798          }
799    
800          if (numModifyDNs > 0)
801          {
802            out("Average modify DN operation processing duration:  ",
803                decimalFormat.format(modifyDNProcessingDuration / numModifyDNs),
804                "ms");
805          }
806    
807          if (numSearches > 0)
808          {
809            out("Average search operation processing duration:  ",
810                decimalFormat.format(searchProcessingDuration / numSearches), "ms");
811          }
812    
813          printProcessingTimeHistogram("add", numAdds, addProcessingTimes);
814          printProcessingTimeHistogram("bind", numBinds, bindProcessingTimes);
815          printProcessingTimeHistogram("compare", numCompares,
816                                       compareProcessingTimes);
817          printProcessingTimeHistogram("delete", numDeletes, deleteProcessingTimes);
818          printProcessingTimeHistogram("extended", numExtended,
819                                       extendedProcessingTimes);
820          printProcessingTimeHistogram("modify", numModifies,
821                                       modifyProcessingTimes);
822          printProcessingTimeHistogram("modify DN", numModifyDNs,
823                                     modifyDNProcessingTimes);
824          printProcessingTimeHistogram("search", numSearches,
825                                       searchProcessingTimes);
826    
827          if (! addResultCodes.isEmpty())
828          {
829            final List<ObjectPair<ResultCode,Long>> rcCounts =
830                 getMostCommonElements(addResultCodes, 20);
831    
832            out();
833            out("Most common add operation result codes:");
834            for (final ObjectPair<ResultCode,Long> p : rcCounts)
835            {
836              final long count = p.getSecond();
837              final double percent = 100.0 * count / numAdds;
838              out(p.getFirst().getName(), ":  ", p.getSecond(), " (",
839                  decimalFormat.format(percent), "%)");
840            }
841          }
842    
843          if (! bindResultCodes.isEmpty())
844          {
845            final List<ObjectPair<ResultCode,Long>> rcCounts =
846                 getMostCommonElements(bindResultCodes, 20);
847    
848            out();
849            out("Most common bind operation result codes:");
850            for (final ObjectPair<ResultCode,Long> p : rcCounts)
851            {
852              final long count = p.getSecond();
853              final double percent = 100.0 * count / numBinds;
854              out(p.getFirst().getName(), ":  ", p.getSecond(), " (",
855                  decimalFormat.format(percent), "%)");
856            }
857          }
858    
859          if (! compareResultCodes.isEmpty())
860          {
861            final List<ObjectPair<ResultCode,Long>> rcCounts =
862                 getMostCommonElements(compareResultCodes, 20);
863    
864            out();
865            out("Most common compare operation result codes:");
866            for (final ObjectPair<ResultCode,Long> p : rcCounts)
867            {
868              final long count = p.getSecond();
869              final double percent = 100.0 * count / numCompares;
870              out(p.getFirst().getName(), ":  ", p.getSecond(), " (",
871                  decimalFormat.format(percent), "%)");
872            }
873          }
874    
875          if (! deleteResultCodes.isEmpty())
876          {
877            final List<ObjectPair<ResultCode,Long>> rcCounts =
878                 getMostCommonElements(deleteResultCodes, 20);
879    
880            out();
881            out("Most common delete operation result codes:");
882            for (final ObjectPair<ResultCode,Long> p : rcCounts)
883            {
884              final long count = p.getSecond();
885              final double percent = 100.0 * count / numDeletes;
886              out(p.getFirst().getName(), ":  ", p.getSecond(), " (",
887                  decimalFormat.format(percent), "%)");
888            }
889          }
890    
891          if (! extendedResultCodes.isEmpty())
892          {
893            final List<ObjectPair<ResultCode,Long>> rcCounts =
894                 getMostCommonElements(extendedResultCodes, 20);
895    
896            out();
897            out("Most common extended operation result codes:");
898            for (final ObjectPair<ResultCode,Long> p : rcCounts)
899            {
900              final long count = p.getSecond();
901              final double percent = 100.0 * count / numExtended;
902              out(p.getFirst().getName(), ":  ", p.getSecond(), " (",
903                  decimalFormat.format(percent), "%)");
904            }
905          }
906    
907          if (! modifyResultCodes.isEmpty())
908          {
909            final List<ObjectPair<ResultCode,Long>> rcCounts =
910                 getMostCommonElements(modifyResultCodes, 20);
911    
912            out();
913            out("Most common modify operation result codes:");
914            for (final ObjectPair<ResultCode,Long> p : rcCounts)
915            {
916              final long count = p.getSecond();
917              final double percent = 100.0 * count / numModifies;
918              out(p.getFirst().getName(), ":  ", p.getSecond(), " (",
919                  decimalFormat.format(percent), "%)");
920            }
921          }
922    
923          if (! modifyDNResultCodes.isEmpty())
924          {
925            final List<ObjectPair<ResultCode,Long>> rcCounts =
926                 getMostCommonElements(modifyDNResultCodes, 20);
927    
928            out();
929            out("Most common modify DN operation result codes:");
930            for (final ObjectPair<ResultCode,Long> p : rcCounts)
931            {
932              final long count = p.getSecond();
933              final double percent = 100.0 * count / numModifyDNs;
934              out(p.getFirst().getName(), ":  ", p.getSecond(), " (",
935                  decimalFormat.format(percent), "%)");
936            }
937          }
938    
939          if (! searchResultCodes.isEmpty())
940          {
941            final List<ObjectPair<ResultCode,Long>> rcCounts =
942                 getMostCommonElements(searchResultCodes, 20);
943    
944            out();
945            out("Most common search operation result codes:");
946            for (final ObjectPair<ResultCode,Long> p : rcCounts)
947            {
948              final long count = p.getSecond();
949              final double percent = 100.0 * count / numSearches;
950              out(p.getFirst().getName(), ":  ", p.getSecond(), " (",
951                  decimalFormat.format(percent), "%)");
952            }
953          }
954    
955          if (! extendedOperations.isEmpty())
956          {
957            final List<ObjectPair<String,Long>> extOpCounts =
958                 getMostCommonElements(extendedOperations, 20);
959    
960            out();
961            out("Most common extended operation types:");
962            for (final ObjectPair<String,Long> p : extOpCounts)
963            {
964              final long count = p.getSecond();
965              final double percent = 100.0 * count / numExtended;
966              out(p.getFirst(), ":  ", p.getSecond(), " (",
967                  decimalFormat.format(percent), "%)");
968            }
969          }
970    
971          out();
972          out("Number of unindexed search attempts:  ", numUnindexedAttempts);
973          out("Number of successfully-completed unindexed searches:  ",
974               numUnindexedSuccessful);
975          out("Number of failed unindexed searches:  ", numUnindexedFailed);
976    
977          if (! searchScopes.isEmpty())
978          {
979            final List<ObjectPair<SearchScope,Long>> scopeCounts =
980                 getMostCommonElements(searchScopes, 20);
981    
982            out();
983            out("Most common search scopes:");
984            for (final ObjectPair<SearchScope,Long> p : scopeCounts)
985            {
986              final long count = p.getSecond();
987              final double percent = 100.0 * count / numSearches;
988              out(p.getFirst().getName(), ":  ", p.getSecond(), " (",
989                  decimalFormat.format(percent), "%)");
990            }
991          }
992    
993          if (! searchEntryCounts.isEmpty())
994          {
995            final List<ObjectPair<Long,Long>> entryCounts =
996                 getMostCommonElements(searchEntryCounts, 20);
997    
998            out();
999            out("Most common search entry counts:");
1000            for (final ObjectPair<Long,Long> p : entryCounts)
1001            {
1002              final long count = p.getSecond();
1003              final double percent = 100.0 * count / numSearches;
1004              out(p.getFirst(), ":  ", p.getSecond(), " (",
1005                  decimalFormat.format(percent), "%)");
1006            }
1007          }
1008    
1009          if (! filterTypes.isEmpty())
1010          {
1011            final List<ObjectPair<String,Long>> filterCounts =
1012                 getMostCommonElements(filterTypes, 20);
1013    
1014            out();
1015            out("Most common generic filters for searches with a non-base scope:");
1016            for (final ObjectPair<String,Long> p : filterCounts)
1017            {
1018              final long count = p.getSecond();
1019              final double percent = 100.0 * count / numNonBaseSearches;
1020              out(p.getFirst(), ":  ", p.getSecond(), " (",
1021                  decimalFormat.format(percent), "%)");
1022            }
1023          }
1024        }
1025    
1026        final long totalUncached = numUncachedAdds + numUncachedBinds +
1027             numUncachedCompares + numUncachedDeletes + numUncachedExtended +
1028             numUncachedModifies + numUncachedModifyDNs + numUncachedSearches;
1029        if (totalUncached > 0L)
1030        {
1031          out();
1032          out("Operations accessing uncached data:");
1033          printUncached("Add", numUncachedAdds, numAdds);
1034          printUncached("Bind", numUncachedBinds, numBinds);
1035          printUncached("Compare", numUncachedCompares, numCompares);
1036          printUncached("Delete", numUncachedDeletes, numDeletes);
1037          printUncached("Extended", numUncachedExtended, numExtended);
1038          printUncached("Modify", numUncachedModifies, numModifies);
1039          printUncached("Modify DN", numUncachedModifyDNs, numModifyDNs);
1040          printUncached("Search", numUncachedSearches, numSearches);
1041        }
1042    
1043    
1044        return ResultCode.SUCCESS;
1045      }
1046    
1047    
1048    
1049      /**
1050       * Retrieves a set of information that may be used to generate example usage
1051       * information.  Each element in the returned map should consist of a map
1052       * between an example set of arguments and a string that describes the
1053       * behavior of the tool when invoked with that set of arguments.
1054       *
1055       * @return  A set of information that may be used to generate example usage
1056       *          information.  It may be {@code null} or empty if no example usage
1057       *          information is available.
1058       */
1059      @Override()
1060      public LinkedHashMap<String[],String> getExampleUsages()
1061      {
1062        final LinkedHashMap<String[],String> examples =
1063             new LinkedHashMap<String[],String>(1);
1064    
1065        final String[] args =
1066        {
1067          "/ds/logs/access"
1068        };
1069        final String description =
1070             "Analyze the contents of the /ds/logs/access access log file.";
1071        examples.put(args, description);
1072    
1073        return examples;
1074      }
1075    
1076    
1077    
1078      /**
1079       * Populates the provided processing time map with an initial set of values.
1080       *
1081       * @param  m  The processing time map to be populated.
1082       */
1083      private static void populateProcessingTimeMap(
1084                               final HashMap<Long,AtomicLong> m)
1085      {
1086        m.put(1L, new AtomicLong(0L));
1087        m.put(2L, new AtomicLong(0L));
1088        m.put(3L, new AtomicLong(0L));
1089        m.put(5L, new AtomicLong(0L));
1090        m.put(10L, new AtomicLong(0L));
1091        m.put(20L, new AtomicLong(0L));
1092        m.put(30L, new AtomicLong(0L));
1093        m.put(50L, new AtomicLong(0L));
1094        m.put(100L, new AtomicLong(0L));
1095        m.put(1000L, new AtomicLong(0L));
1096        m.put(Long.MAX_VALUE, new AtomicLong(0L));
1097      }
1098    
1099    
1100    
1101      /**
1102       * Performs any necessary processing for a connect message.
1103       *
1104       * @param  m  The log message to be processed.
1105       */
1106      private void processConnect(final ConnectAccessLogMessage m)
1107      {
1108        numConnects++;
1109    
1110        final String clientAddr = m.getSourceAddress();
1111        if (clientAddr != null)
1112        {
1113          AtomicLong count = clientAddresses.get(clientAddr);
1114          if (count == null)
1115          {
1116            count = new AtomicLong(0L);
1117            clientAddresses.put(clientAddr, count);
1118          }
1119          count.incrementAndGet();
1120        }
1121    
1122        final String ccp = m.getClientConnectionPolicy();
1123        if (ccp != null)
1124        {
1125          AtomicLong l = clientConnectionPolicies.get(ccp);
1126          if (l == null)
1127          {
1128            l = new AtomicLong(0L);
1129            clientConnectionPolicies.put(ccp, l);
1130          }
1131          l.incrementAndGet();
1132        }
1133      }
1134    
1135    
1136    
1137      /**
1138       * Performs any necessary processing for a disconnect message.
1139       *
1140       * @param  m  The log message to be processed.
1141       */
1142      private void processDisconnect(final DisconnectAccessLogMessage m)
1143      {
1144        numDisconnects++;
1145    
1146        final String reason = m.getDisconnectReason();
1147        if (reason != null)
1148        {
1149          AtomicLong l = disconnectReasons.get(reason);
1150          if (l == null)
1151          {
1152            l = new AtomicLong(0L);
1153            disconnectReasons.put(reason, l);
1154          }
1155          l.incrementAndGet();
1156        }
1157      }
1158    
1159    
1160    
1161      /**
1162       * Performs any necessary processing for an abandon request message.
1163       *
1164       * @param  m  The log message to be processed.
1165       */
1166      private void processAbandonRequest(final AbandonRequestAccessLogMessage m)
1167      {
1168        numAbandons++;
1169      }
1170    
1171    
1172    
1173      /**
1174       * Performs any necessary processing for an extended request message.
1175       *
1176       * @param  m  The log message to be processed.
1177       */
1178      private void processExtendedRequest(final ExtendedRequestAccessLogMessage m)
1179      {
1180        processedRequests.add(m.getConnectionID() + "-" + m.getOperationID());
1181        processExtendedRequestInternal(m);
1182      }
1183    
1184    
1185    
1186      /**
1187       * Performs the internal processing for an extended request message.
1188       *
1189       * @param  m  The log message to be processed.
1190       */
1191      private void processExtendedRequestInternal(
1192                        final ExtendedRequestAccessLogMessage m)
1193      {
1194        final String oid = m.getRequestOID();
1195        if (oid != null)
1196        {
1197          AtomicLong l = extendedOperations.get(oid);
1198          if (l == null)
1199          {
1200            l  = new AtomicLong(0L);
1201            extendedOperations.put(oid, l);
1202          }
1203          l.incrementAndGet();
1204        }
1205      }
1206    
1207    
1208    
1209      /**
1210       * Performs any necessary processing for a search request message.
1211       *
1212       * @param  m  The log message to be processed.
1213       */
1214      private void processSearchRequest(final SearchRequestAccessLogMessage m)
1215      {
1216        processedRequests.add(m.getConnectionID() + "-" + m.getOperationID());
1217        processSearchRequestInternal(m);
1218      }
1219    
1220    
1221    
1222      /**
1223       * Performs any necessary processing for a search request message.
1224       *
1225       * @param  m  The log message to be processed.
1226       */
1227      private void processSearchRequestInternal(
1228                        final SearchRequestAccessLogMessage m)
1229      {
1230        final SearchScope scope = m.getScope();
1231        if (scope != null)
1232        {
1233          if (scope != SearchScope.BASE)
1234          {
1235            numNonBaseSearches++;
1236          }
1237    
1238          AtomicLong scopeCount = searchScopes.get(scope);
1239          if (scopeCount == null)
1240          {
1241            scopeCount = new AtomicLong(0L);
1242            searchScopes.put(scope, scopeCount);
1243          }
1244          scopeCount.incrementAndGet();
1245    
1246          if (! scope.equals(SearchScope.BASE))
1247          {
1248            final Filter filter = m.getParsedFilter();
1249            if (filter != null)
1250            {
1251              final String genericString = new GenericFilter(filter).toString();
1252              AtomicLong filterCount = filterTypes.get(genericString);
1253              if (filterCount == null)
1254              {
1255                filterCount = new AtomicLong(0L);
1256                filterTypes.put(genericString, filterCount);
1257              }
1258              filterCount.incrementAndGet();
1259            }
1260          }
1261        }
1262      }
1263    
1264    
1265    
1266      /**
1267       * Performs any necessary processing for an unbind request message.
1268       *
1269       * @param  m  The log message to be processed.
1270       */
1271      private void processUnbindRequest(final UnbindRequestAccessLogMessage m)
1272      {
1273        numUnbinds++;
1274      }
1275    
1276    
1277    
1278      /**
1279       * Performs any necessary processing for an add result message.
1280       *
1281       * @param  m  The log message to be processed.
1282       */
1283      private void processAddResult(final AddResultAccessLogMessage m)
1284      {
1285        numAdds++;
1286    
1287        updateResultCodeCount(m.getResultCode(), addResultCodes);
1288        addProcessingDuration +=
1289             doubleValue(m.getProcessingTimeMillis(), addProcessingTimes);
1290    
1291        final Boolean uncachedDataAccessed = m.getUncachedDataAccessed();
1292        if ((uncachedDataAccessed != null) && uncachedDataAccessed)
1293        {
1294          numUncachedAdds++;
1295        }
1296      }
1297    
1298    
1299    
1300      /**
1301       * Performs any necessary processing for a bind result message.
1302       *
1303       * @param  m  The log message to be processed.
1304       */
1305      private void processBindResult(final BindResultAccessLogMessage m)
1306      {
1307        numBinds++;
1308    
1309        updateResultCodeCount(m.getResultCode(), bindResultCodes);
1310        bindProcessingDuration +=
1311             doubleValue(m.getProcessingTimeMillis(), bindProcessingTimes);
1312    
1313        final String ccp = m.getClientConnectionPolicy();
1314        if (ccp != null)
1315        {
1316          AtomicLong l = clientConnectionPolicies.get(ccp);
1317          if (l == null)
1318          {
1319            l = new AtomicLong(0L);
1320            clientConnectionPolicies.put(ccp, l);
1321          }
1322          l.incrementAndGet();
1323        }
1324    
1325        final Boolean uncachedDataAccessed = m.getUncachedDataAccessed();
1326        if ((uncachedDataAccessed != null) && uncachedDataAccessed)
1327        {
1328          numUncachedBinds++;
1329        }
1330      }
1331    
1332    
1333    
1334      /**
1335       * Performs any necessary processing for a compare result message.
1336       *
1337       * @param  m  The log message to be processed.
1338       */
1339      private void processCompareResult(final CompareResultAccessLogMessage m)
1340      {
1341        numCompares++;
1342    
1343        updateResultCodeCount(m.getResultCode(), compareResultCodes);
1344        compareProcessingDuration +=
1345             doubleValue(m.getProcessingTimeMillis(), compareProcessingTimes);
1346    
1347        final Boolean uncachedDataAccessed = m.getUncachedDataAccessed();
1348        if ((uncachedDataAccessed != null) && uncachedDataAccessed)
1349        {
1350          numUncachedCompares++;
1351        }
1352      }
1353    
1354    
1355    
1356      /**
1357       * Performs any necessary processing for a delete result message.
1358       *
1359       * @param  m  The log message to be processed.
1360       */
1361      private void processDeleteResult(final DeleteResultAccessLogMessage m)
1362      {
1363        numDeletes++;
1364    
1365        updateResultCodeCount(m.getResultCode(), deleteResultCodes);
1366        deleteProcessingDuration +=
1367             doubleValue(m.getProcessingTimeMillis(), deleteProcessingTimes);
1368    
1369        final Boolean uncachedDataAccessed = m.getUncachedDataAccessed();
1370        if ((uncachedDataAccessed != null) && uncachedDataAccessed)
1371        {
1372          numUncachedDeletes++;
1373        }
1374      }
1375    
1376    
1377    
1378      /**
1379       * Performs any necessary processing for an extended result message.
1380       *
1381       * @param  m  The log message to be processed.
1382       */
1383      private void processExtendedResult(final ExtendedResultAccessLogMessage m)
1384      {
1385        numExtended++;
1386    
1387        final String id = m.getConnectionID() + "-" + m.getOperationID();
1388        if (!processedRequests.remove(id))
1389        {
1390          processExtendedRequestInternal(m);
1391        }
1392    
1393        updateResultCodeCount(m.getResultCode(), extendedResultCodes);
1394        extendedProcessingDuration +=
1395             doubleValue(m.getProcessingTimeMillis(), extendedProcessingTimes);
1396    
1397        final String ccp = m.getClientConnectionPolicy();
1398        if (ccp != null)
1399        {
1400          AtomicLong l = clientConnectionPolicies.get(ccp);
1401          if (l == null)
1402          {
1403            l = new AtomicLong(0L);
1404            clientConnectionPolicies.put(ccp, l);
1405          }
1406          l.incrementAndGet();
1407        }
1408    
1409        final Boolean uncachedDataAccessed = m.getUncachedDataAccessed();
1410        if ((uncachedDataAccessed != null) && uncachedDataAccessed)
1411        {
1412          numUncachedExtended++;
1413        }
1414      }
1415    
1416    
1417    
1418      /**
1419       * Performs any necessary processing for a modify result message.
1420       *
1421       * @param  m  The log message to be processed.
1422       */
1423      private void processModifyResult(final ModifyResultAccessLogMessage m)
1424      {
1425        numModifies++;
1426    
1427        updateResultCodeCount(m.getResultCode(), modifyResultCodes);
1428        modifyProcessingDuration +=
1429             doubleValue(m.getProcessingTimeMillis(), modifyProcessingTimes);
1430    
1431        final Boolean uncachedDataAccessed = m.getUncachedDataAccessed();
1432        if ((uncachedDataAccessed != null) && uncachedDataAccessed)
1433        {
1434          numUncachedModifies++;
1435        }
1436      }
1437    
1438    
1439    
1440      /**
1441       * Performs any necessary processing for a modify DN result message.
1442       *
1443       * @param  m  The log message to be processed.
1444       */
1445      private void processModifyDNResult(final ModifyDNResultAccessLogMessage m)
1446      {
1447        numModifyDNs++;
1448    
1449        updateResultCodeCount(m.getResultCode(), modifyDNResultCodes);
1450        modifyDNProcessingDuration +=
1451             doubleValue(m.getProcessingTimeMillis(), modifyDNProcessingTimes);
1452    
1453        final Boolean uncachedDataAccessed = m.getUncachedDataAccessed();
1454        if ((uncachedDataAccessed != null) && uncachedDataAccessed)
1455        {
1456          numUncachedModifyDNs++;
1457        }
1458      }
1459    
1460    
1461    
1462      /**
1463       * Performs any necessary processing for a search result message.
1464       *
1465       * @param  m  The log message to be processed.
1466       */
1467      private void processSearchResult(final SearchResultAccessLogMessage m)
1468      {
1469        numSearches++;
1470    
1471        final String id = m.getConnectionID() + "-" + m.getOperationID();
1472        if (!processedRequests.remove(id))
1473        {
1474          processSearchRequestInternal(m);
1475        }
1476    
1477        final ResultCode resultCode = m.getResultCode();
1478        updateResultCodeCount(resultCode, searchResultCodes);
1479        searchProcessingDuration +=
1480             doubleValue(m.getProcessingTimeMillis(), searchProcessingTimes);
1481    
1482        final Long entryCount = m.getEntriesReturned();
1483        if (entryCount != null)
1484        {
1485          AtomicLong l = searchEntryCounts.get(entryCount);
1486          if (l == null)
1487          {
1488            l = new AtomicLong(0L);
1489            searchEntryCounts.put(entryCount, l);
1490          }
1491          l.incrementAndGet();
1492        }
1493    
1494        final Boolean isUnindexed = m.isUnindexed();
1495        if ((isUnindexed != null) && isUnindexed)
1496        {
1497          numUnindexedAttempts++;
1498          if (resultCode == ResultCode.SUCCESS)
1499          {
1500            numUnindexedSuccessful++;
1501          }
1502          else
1503          {
1504            numUnindexedFailed++;
1505          }
1506        }
1507    
1508        final Boolean uncachedDataAccessed = m.getUncachedDataAccessed();
1509        if ((uncachedDataAccessed != null) && uncachedDataAccessed)
1510        {
1511          numUncachedSearches++;
1512        }
1513      }
1514    
1515    
1516    
1517      /**
1518       * Updates the count for the provided result code in the given map.
1519       *
1520       * @param  rc  The result code for which to update the count.
1521       * @param  m   The map used to hold counts by result code.
1522       */
1523      private static void updateResultCodeCount(final ResultCode rc,
1524                               final HashMap<ResultCode,AtomicLong> m)
1525      {
1526        if (rc == null)
1527        {
1528          return;
1529        }
1530    
1531        AtomicLong l = m.get(rc);
1532        if (l == null)
1533        {
1534          l = new AtomicLong(0L);
1535          m.put(rc, l);
1536        }
1537        l.incrementAndGet();
1538      }
1539    
1540    
1541    
1542      /**
1543       * Retrieves the double value for the provided {@code Double} object.
1544       *
1545       * @param  d  The {@code Double} object for which to retrieve the value.
1546       * @param  m  The processing time histogram map to be updated.
1547       *
1548       * @return  The double value of the provided {@code Double} object if it was
1549       *          non-{@code null}, or 0.0 if it was {@code null}.
1550       */
1551      private static double doubleValue(final Double d,
1552                                        final HashMap<Long,AtomicLong> m)
1553      {
1554        if (d == null)
1555        {
1556          return 0.0;
1557        }
1558        else
1559        {
1560          for (final Map.Entry<Long,AtomicLong> e : m.entrySet())
1561          {
1562            if (d <= e.getKey())
1563            {
1564              e.getValue().incrementAndGet();
1565              break;
1566            }
1567          }
1568    
1569          return d;
1570        }
1571      }
1572    
1573    
1574    
1575      /**
1576       * Retrieves a list of the most frequently-occurring elements in the
1577       * provided map, paired with the number of times each value occurred.
1578       *
1579       * @param  <K>  The type of object used as the key for the provided map.
1580       * @param  m    The map to be examined.  It is expected that the values of the
1581       *              map will be the count of occurrences for the keys.
1582       * @param  n    The number of elements to return.
1583       *
1584       * @return  A list of the most frequently-occurring elements in the provided
1585       *          map.
1586       */
1587      private static <K> List<ObjectPair<K,Long>> getMostCommonElements(
1588                                                       final Map<K,AtomicLong> m,
1589                                                       final int n)
1590      {
1591        final TreeMap<Long,List<K>> reverseMap =
1592             new TreeMap<Long,List<K>>(new ReverseComparator<Long>());
1593        for (final Map.Entry<K,AtomicLong> e : m.entrySet())
1594        {
1595          final Long count = e.getValue().get();
1596          List<K> list = reverseMap.get(count);
1597          if (list == null)
1598          {
1599            list = new ArrayList<K>(n);
1600            reverseMap.put(count, list);
1601          }
1602          list.add(e.getKey());
1603        }
1604    
1605        final ArrayList<ObjectPair<K,Long>> returnList =
1606             new ArrayList<ObjectPair<K,Long>>(n);
1607        for (final Map.Entry<Long,List<K>> e : reverseMap.entrySet())
1608        {
1609          final Long l = e.getKey();
1610          for (final K k : e.getValue())
1611          {
1612            returnList.add(new ObjectPair<K,Long>(k, l));
1613          }
1614    
1615          if (returnList.size() >= n)
1616          {
1617            break;
1618          }
1619        }
1620    
1621        return returnList;
1622      }
1623    
1624    
1625    
1626      /**
1627       * Writes a breakdown of the processing times for a specified type of
1628       * operation.
1629       *
1630       * @param  t  The name of the operation type.
1631       * @param  n  The total number of operations of the specified type that were
1632       *            processed by the server.
1633       * @param  m  The map of operation counts by processing time bucket.
1634       */
1635      private void printProcessingTimeHistogram(final String t, final long n,
1636                        final LinkedHashMap<Long,AtomicLong> m)
1637      {
1638        if (n <= 0)
1639        {
1640          return;
1641        }
1642    
1643        out();
1644        out("Count of ", t, " operations by processing time:");
1645    
1646        long lowerBound = 0;
1647        long accumulatedCount = 0;
1648        final Iterator<Map.Entry<Long,AtomicLong>> i = m.entrySet().iterator();
1649        while (i.hasNext())
1650        {
1651          final Map.Entry<Long,AtomicLong> e = i.next();
1652          final long upperBound = e.getKey();
1653          final long count = e.getValue().get();
1654          final double categoryPercent = 100.0 * count / n;
1655    
1656          accumulatedCount += count;
1657          final double accumulatedPercent = 100.0 * accumulatedCount / n;
1658    
1659          if (i.hasNext())
1660          {
1661            out("Between ", lowerBound, "ms and ", upperBound, "ms:  ",
1662                count, " (", decimalFormat.format(categoryPercent), "%, ",
1663                decimalFormat.format(accumulatedPercent), "% accumulated)");
1664            lowerBound = upperBound;
1665          }
1666          else
1667          {
1668            out("Greater than ", lowerBound, "ms:  ", count, " (",
1669                decimalFormat.format(categoryPercent), "%, ",
1670                decimalFormat.format(accumulatedPercent), "% accumulated)");
1671          }
1672        }
1673      }
1674    
1675    
1676    
1677      /**
1678       * Optionally prints information about the number and percent of operations of
1679       * the specified type that involved access to uncached data.
1680       *
1681       * @param  operationType  The type of operation.
1682       * @param  numUncached    The number of operations of the specified type that
1683       *                        involved access to uncached data.
1684       * @param  numTotal       The total number of operations of the specified
1685       *                        type.
1686       */
1687      private void printUncached(final String operationType, final long numUncached,
1688                                 final long numTotal)
1689      {
1690        if (numUncached == 0)
1691        {
1692          return;
1693        }
1694    
1695        out(operationType, ":  ", numUncached, " (",
1696             decimalFormat.format(100.0 * numUncached / numTotal), "%)");
1697      }
1698    }