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