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