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