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