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