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