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}