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