001/* 002 * Copyright 2009-2022 Ping Identity Corporation 003 * All Rights Reserved. 004 */ 005/* 006 * Copyright 2009-2022 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) 2009-2022 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.IOException; 044import java.io.OutputStream; 045import java.io.Serializable; 046import java.text.DecimalFormat; 047import java.util.ArrayList; 048import java.util.HashMap; 049import java.util.HashSet; 050import java.util.Iterator; 051import java.util.LinkedHashMap; 052import java.util.List; 053import java.util.Map; 054import java.util.TreeMap; 055import java.util.concurrent.atomic.AtomicLong; 056import java.util.zip.GZIPInputStream; 057import javax.crypto.BadPaddingException; 058 059import com.unboundid.ldap.sdk.DN; 060import com.unboundid.ldap.sdk.Filter; 061import com.unboundid.ldap.sdk.LDAPException; 062import com.unboundid.ldap.sdk.RDN; 063import com.unboundid.ldap.sdk.ResultCode; 064import com.unboundid.ldap.sdk.SearchScope; 065import com.unboundid.ldap.sdk.Version; 066import com.unboundid.ldap.sdk.unboundidds.logs.LogException; 067import com.unboundid.ldap.sdk.unboundidds.logs.v2. 068 AbandonRequestAccessLogMessage; 069import com.unboundid.ldap.sdk.unboundidds.logs.v2.AccessLogMessage; 070import com.unboundid.ldap.sdk.unboundidds.logs.v2.AccessLogReader; 071import com.unboundid.ldap.sdk.unboundidds.logs.v2.AddResultAccessLogMessage; 072import com.unboundid.ldap.sdk.unboundidds.logs.v2.BindResultAccessLogMessage; 073import com.unboundid.ldap.sdk.unboundidds.logs.v2.CompareResultAccessLogMessage; 074import com.unboundid.ldap.sdk.unboundidds.logs.v2.ConnectAccessLogMessage; 075import com.unboundid.ldap.sdk.unboundidds.logs.v2.DeleteResultAccessLogMessage; 076import com.unboundid.ldap.sdk.unboundidds.logs.v2.DisconnectAccessLogMessage; 077import com.unboundid.ldap.sdk.unboundidds.logs.v2. 078 ExtendedRequestAccessLogMessage; 079import com.unboundid.ldap.sdk.unboundidds.logs.v2. 080 ExtendedResultAccessLogMessage; 081import com.unboundid.ldap.sdk.unboundidds.logs.v2. 082 ModifyDNResultAccessLogMessage; 083import com.unboundid.ldap.sdk.unboundidds.logs.v2.ModifyResultAccessLogMessage; 084import com.unboundid.ldap.sdk.unboundidds.logs.v2. 085 OperationRequestAccessLogMessage; 086import com.unboundid.ldap.sdk.unboundidds.logs.v2.SearchRequestAccessLogMessage; 087import com.unboundid.ldap.sdk.unboundidds.logs.v2.SearchResultAccessLogMessage; 088import com.unboundid.ldap.sdk.unboundidds.logs.v2. 089 SecurityNegotiationAccessLogMessage; 090import com.unboundid.ldap.sdk.unboundidds.logs.v2.UnbindRequestAccessLogMessage; 091import com.unboundid.ldap.sdk.unboundidds.logs.v2.json.JSONAccessLogReader; 092import com.unboundid.ldap.sdk.unboundidds.logs.v2.text. 093 TextFormattedAccessLogReader; 094import com.unboundid.ldap.sdk.unboundidds.tools.ToolUtils; 095import com.unboundid.util.CommandLineTool; 096import com.unboundid.util.Debug; 097import com.unboundid.util.NotMutable; 098import com.unboundid.util.NotNull; 099import com.unboundid.util.Nullable; 100import com.unboundid.util.ObjectPair; 101import com.unboundid.util.ReverseComparator; 102import com.unboundid.util.StaticUtils; 103import com.unboundid.util.ThreadSafety; 104import com.unboundid.util.ThreadSafetyLevel; 105import com.unboundid.util.args.ArgumentException; 106import com.unboundid.util.args.ArgumentParser; 107import com.unboundid.util.args.BooleanArgument; 108import com.unboundid.util.args.DurationArgument; 109import com.unboundid.util.args.FileArgument; 110import com.unboundid.util.args.IntegerArgument; 111 112 113 114/** 115 * This class provides a tool that may be used to read and summarize the 116 * contents of one or more access log files from Ping Identity, UnboundID and 117 * Nokia/Alcatel-Lucent 8661 server products. 118 * <BR> 119 * <BLOCKQUOTE> 120 * <B>NOTE:</B> This class, and other classes within the 121 * {@code com.unboundid.ldap.sdk.unboundidds} package structure, are only 122 * supported for use against Ping Identity, UnboundID, and 123 * Nokia/Alcatel-Lucent 8661 server products. These classes provide support 124 * for proprietary functionality or for external specifications that are not 125 * considered stable or mature enough to be guaranteed to work in an 126 * interoperable way with other types of LDAP servers. 127 * </BLOCKQUOTE> 128 * Information that will be reported includes: 129 * <UL> 130 * <LI>The total length of time covered by the log files.</LI> 131 * <LI>The number of connections established and disconnected, the addresses 132 * of the most commonly-connecting clients, and the average rate of 133 * connects and disconnects per second.</LI> 134 * <LI>The number of operations processed, overall and by operation type, 135 * and the average rate of operations per second.</LI> 136 * <LI>The average duration for operations processed, overall and by operation 137 * type.</LI> 138 * <LI>A breakdown of operation processing times into a number of predefined 139 * categories, ranging from less than one millisecond to over one 140 * minute.</LI> 141 * <LI>A breakdown of the most common result codes for each type of operation 142 * and their relative frequencies.</LI> 143 * <LI>The most common types of extended requests processed and their 144 * relative frequencies.</LI> 145 * <LI>The number of unindexed search operations processed and the most common 146 * types of filters used in unindexed searches.</LI> 147 * <LI>A breakdown of the relative frequencies for each type of search 148 * scope.</LI> 149 * <LI>The most common types of search filters used for search 150 * operations and their relative frequencies.</LI> 151 * </UL> 152 * It is designed to work with access log files using either the default log 153 * format with separate request and response messages, as well as log files 154 * in which the request and response details have been combined on the same 155 * line. The log files to be processed should be provided as command-line 156 * arguments. 157 * <BR><BR> 158 * The APIs demonstrated by this example include: 159 * <UL> 160 * <LI>Access log parsing (from the 161 * {@code com.unboundid.ldap.sdk.unboundidds.logs} package)</LI> 162 * <LI>Argument parsing (from the {@code com.unboundid.util.args} 163 * package)</LI> 164 * </UL> 165 */ 166@NotMutable() 167@ThreadSafety(level=ThreadSafetyLevel.NOT_THREADSAFE) 168public final class SummarizeAccessLog 169 extends CommandLineTool 170 implements Serializable 171{ 172 /** 173 * The serial version UID for this serializable class. 174 */ 175 private static final long serialVersionUID = 7189168366509887130L; 176 177 178 179 // Variables used for accessing argument information. 180 @Nullable private ArgumentParser argumentParser; 181 182 // An argument that may be used to indicate that the summarized output should 183 // not be anonymized, and should include attribute values. 184 @Nullable private BooleanArgument doNotAnonymize; 185 186 // An argument that may be used to indicate that the log files are compressed. 187 @Nullable private BooleanArgument isCompressed; 188 189 // An argument that may be used to indicate that the log content is 190 // JSON-formatted rather than text-formatted. 191 @Nullable private BooleanArgument json; 192 193 // An argument used to specify the encryption passphrase. 194 @Nullable private FileArgument encryptionPassphraseFile; 195 196 // An argument used to specify the maximum number of values to report for each 197 // item. 198 @Nullable private IntegerArgument reportCount; 199 200 // The decimal format that will be used for this class. 201 @NotNull private final DecimalFormat decimalFormat; 202 203 // The total duration for log content, in milliseconds. 204 private long logDurationMillis; 205 206 // The total processing time for each type of operation. 207 private double addProcessingDuration; 208 private double bindProcessingDuration; 209 private double compareProcessingDuration; 210 private double deleteProcessingDuration; 211 private double extendedProcessingDuration; 212 private double modifyProcessingDuration; 213 private double modifyDNProcessingDuration; 214 private double searchProcessingDuration; 215 216 // A variable used for counting the number of messages of each type. 217 private long numAbandons; 218 private long numAdds; 219 private long numBinds; 220 private long numCompares; 221 private long numConnects; 222 private long numDeletes; 223 private long numDisconnects; 224 private long numExtended; 225 private long numModifies; 226 private long numModifyDNs; 227 private long numSearches; 228 private long numUnbinds; 229 230 // The number of operations of each type that accessed uncached data. 231 private long numUncachedAdds; 232 private long numUncachedBinds; 233 private long numUncachedCompares; 234 private long numUncachedDeletes; 235 private long numUncachedExtended; 236 private long numUncachedModifies; 237 private long numUncachedModifyDNs; 238 private long numUncachedSearches; 239 240 // The number of unindexed searches processed within the server. 241 private long numUnindexedAttempts; 242 private long numUnindexedFailed; 243 private long numUnindexedSuccessful; 244 245 // Variables used for maintaining counts for common types of information. 246 @NotNull private final HashMap<Long,AtomicLong> searchEntryCounts; 247 @NotNull private final HashMap<ResultCode,AtomicLong> addResultCodes; 248 @NotNull private final HashMap<ResultCode,AtomicLong> bindResultCodes; 249 @NotNull private final HashMap<ResultCode,AtomicLong> compareResultCodes; 250 @NotNull private final HashMap<ResultCode,AtomicLong> deleteResultCodes; 251 @NotNull private final HashMap<ResultCode,AtomicLong> extendedResultCodes; 252 @NotNull private final HashMap<ResultCode,AtomicLong> modifyResultCodes; 253 @NotNull private final HashMap<ResultCode,AtomicLong> modifyDNResultCodes; 254 @NotNull private final HashMap<ResultCode,AtomicLong> searchResultCodes; 255 @NotNull private final HashMap<SearchScope,AtomicLong> searchScopes; 256 @NotNull private final HashMap<String,AtomicLong> authenticationTypes; 257 @NotNull private final HashMap<String,AtomicLong> authzDNs; 258 @NotNull private final HashMap<String,AtomicLong> failedBindDNs; 259 @NotNull private final HashMap<String,AtomicLong> successfulBindDNs; 260 @NotNull private final HashMap<String,AtomicLong> clientAddresses; 261 @NotNull private final HashMap<String,AtomicLong> clientConnectionPolicies; 262 @NotNull private final HashMap<String,AtomicLong> disconnectReasons; 263 @NotNull private final HashMap<String,AtomicLong> extendedOperations; 264 @NotNull private final HashMap<String,AtomicLong> filterTypes; 265 @NotNull private final HashMap<String,AtomicLong> mostExpensiveFilters; 266 @NotNull private final HashMap<String,AtomicLong> multiEntryFilters; 267 @NotNull private final HashMap<String,AtomicLong> noEntryFilters; 268 @NotNull private final HashMap<String,AtomicLong> oneEntryFilters; 269 @NotNull private final HashMap<String,AtomicLong> searchBaseDNs; 270 @NotNull private final HashMap<String,AtomicLong> tlsCipherSuites; 271 @NotNull private final HashMap<String,AtomicLong> tlsProtocols; 272 @NotNull private final HashMap<String,AtomicLong> unindexedFilters; 273 @NotNull private final HashMap<String,String> extendedOperationOIDsToNames; 274 @NotNull private final HashSet<String> processedRequests; 275 @NotNull private final LinkedHashMap<Long,AtomicLong> addProcessingTimes; 276 @NotNull private final LinkedHashMap<Long,AtomicLong> bindProcessingTimes; 277 @NotNull private final LinkedHashMap<Long,AtomicLong> compareProcessingTimes; 278 @NotNull private final LinkedHashMap<Long,AtomicLong> deleteProcessingTimes; 279 @NotNull private final LinkedHashMap<Long,AtomicLong> extendedProcessingTimes; 280 @NotNull private final LinkedHashMap<Long,AtomicLong> modifyProcessingTimes; 281 @NotNull private final LinkedHashMap<Long,AtomicLong> modifyDNProcessingTimes; 282 @NotNull private final LinkedHashMap<Long,AtomicLong> searchProcessingTimes; 283 284 285 286 /** 287 * Parse the provided command line arguments and perform the appropriate 288 * processing. 289 * 290 * @param args The command line arguments provided to this program. 291 */ 292 public static void main(@NotNull final String[] args) 293 { 294 final ResultCode resultCode = main(args, System.out, System.err); 295 if (resultCode != ResultCode.SUCCESS) 296 { 297 System.exit(resultCode.intValue()); 298 } 299 } 300 301 302 303 /** 304 * Parse the provided command line arguments and perform the appropriate 305 * processing. 306 * 307 * @param args The command line arguments provided to this program. 308 * @param outStream The output stream to which standard out should be 309 * written. It may be {@code null} if output should be 310 * suppressed. 311 * @param errStream The output stream to which standard error should be 312 * written. It may be {@code null} if error messages 313 * should be suppressed. 314 * 315 * @return A result code indicating whether the processing was successful. 316 */ 317 @NotNull() 318 public static ResultCode main(@NotNull final String[] args, 319 @Nullable final OutputStream outStream, 320 @Nullable final OutputStream errStream) 321 { 322 final SummarizeAccessLog summarizer = 323 new SummarizeAccessLog(outStream, errStream); 324 return summarizer.runTool(args); 325 } 326 327 328 329 /** 330 * Creates a new instance of this tool. 331 * 332 * @param outStream The output stream to which standard out should be 333 * written. It may be {@code null} if output should be 334 * suppressed. 335 * @param errStream The output stream to which standard error should be 336 * written. It may be {@code null} if error messages 337 * should be suppressed. 338 */ 339 public SummarizeAccessLog(@Nullable final OutputStream outStream, 340 @Nullable final OutputStream errStream) 341 { 342 super(outStream, errStream); 343 344 argumentParser = null; 345 doNotAnonymize = null; 346 isCompressed = null; 347 json = null; 348 encryptionPassphraseFile = null; 349 reportCount = null; 350 351 decimalFormat = new DecimalFormat("0.000"); 352 353 logDurationMillis = 0L; 354 355 addProcessingDuration = 0.0; 356 bindProcessingDuration = 0.0; 357 compareProcessingDuration = 0.0; 358 deleteProcessingDuration = 0.0; 359 extendedProcessingDuration = 0.0; 360 modifyProcessingDuration = 0.0; 361 modifyDNProcessingDuration = 0.0; 362 searchProcessingDuration = 0.0; 363 364 numAbandons = 0L; 365 numAdds = 0L; 366 numBinds = 0L; 367 numCompares = 0L; 368 numConnects = 0L; 369 numDeletes = 0L; 370 numDisconnects = 0L; 371 numExtended = 0L; 372 numModifies = 0L; 373 numModifyDNs = 0L; 374 numSearches = 0L; 375 numUnbinds = 0L; 376 377 numUncachedAdds = 0L; 378 numUncachedBinds = 0L; 379 numUncachedCompares = 0L; 380 numUncachedDeletes = 0L; 381 numUncachedExtended = 0L; 382 numUncachedModifies = 0L; 383 numUncachedModifyDNs = 0L; 384 numUncachedSearches = 0L; 385 386 numUnindexedAttempts = 0L; 387 numUnindexedFailed = 0L; 388 numUnindexedSuccessful = 0L; 389 390 searchEntryCounts = new HashMap<>(StaticUtils.computeMapCapacity(10)); 391 addResultCodes = new HashMap<>(StaticUtils.computeMapCapacity(10)); 392 bindResultCodes = new HashMap<>(StaticUtils.computeMapCapacity(10)); 393 compareResultCodes = new HashMap<>(StaticUtils.computeMapCapacity(10)); 394 deleteResultCodes = new HashMap<>(StaticUtils.computeMapCapacity(10)); 395 extendedResultCodes = new HashMap<>(StaticUtils.computeMapCapacity(10)); 396 modifyResultCodes = new HashMap<>(StaticUtils.computeMapCapacity(10)); 397 modifyDNResultCodes = new HashMap<>(StaticUtils.computeMapCapacity(10)); 398 searchResultCodes = new HashMap<>(StaticUtils.computeMapCapacity(10)); 399 searchScopes = new HashMap<>(StaticUtils.computeMapCapacity(4)); 400 authenticationTypes = new HashMap<>(StaticUtils.computeMapCapacity(100)); 401 authzDNs = new HashMap<>(StaticUtils.computeMapCapacity(100)); 402 failedBindDNs = new HashMap<>(StaticUtils.computeMapCapacity(100)); 403 successfulBindDNs = new HashMap<>(StaticUtils.computeMapCapacity(100)); 404 clientAddresses = new HashMap<>(StaticUtils.computeMapCapacity(100)); 405 clientConnectionPolicies = 406 new HashMap<>(StaticUtils.computeMapCapacity(100)); 407 disconnectReasons = new HashMap<>(StaticUtils.computeMapCapacity(100)); 408 extendedOperations = new HashMap<>(StaticUtils.computeMapCapacity(10)); 409 filterTypes = new HashMap<>(StaticUtils.computeMapCapacity(100)); 410 mostExpensiveFilters = new HashMap<>(StaticUtils.computeMapCapacity(100)); 411 multiEntryFilters = new HashMap<>(StaticUtils.computeMapCapacity(100)); 412 noEntryFilters = new HashMap<>(StaticUtils.computeMapCapacity(100)); 413 oneEntryFilters = new HashMap<>(StaticUtils.computeMapCapacity(100)); 414 searchBaseDNs = new HashMap<>(StaticUtils.computeMapCapacity(100)); 415 tlsCipherSuites = new HashMap<>(StaticUtils.computeMapCapacity(100)); 416 tlsProtocols = new HashMap<>(StaticUtils.computeMapCapacity(100)); 417 unindexedFilters = new HashMap<>(StaticUtils.computeMapCapacity(100)); 418 extendedOperationOIDsToNames = 419 new HashMap<>(StaticUtils.computeMapCapacity(100)); 420 processedRequests = new HashSet<>(StaticUtils.computeMapCapacity(100)); 421 addProcessingTimes = 422 new LinkedHashMap<>(StaticUtils.computeMapCapacity(11)); 423 bindProcessingTimes = 424 new LinkedHashMap<>(StaticUtils.computeMapCapacity(11)); 425 compareProcessingTimes = 426 new LinkedHashMap<>(StaticUtils.computeMapCapacity(11)); 427 deleteProcessingTimes = 428 new LinkedHashMap<>(StaticUtils.computeMapCapacity(11)); 429 extendedProcessingTimes = 430 new LinkedHashMap<>(StaticUtils.computeMapCapacity(11)); 431 modifyProcessingTimes = 432 new LinkedHashMap<>(StaticUtils.computeMapCapacity(11)); 433 modifyDNProcessingTimes = 434 new LinkedHashMap<>(StaticUtils.computeMapCapacity(11)); 435 searchProcessingTimes = 436 new LinkedHashMap<>(StaticUtils.computeMapCapacity(11)); 437 438 populateProcessingTimeMap(addProcessingTimes); 439 populateProcessingTimeMap(bindProcessingTimes); 440 populateProcessingTimeMap(compareProcessingTimes); 441 populateProcessingTimeMap(deleteProcessingTimes); 442 populateProcessingTimeMap(extendedProcessingTimes); 443 populateProcessingTimeMap(modifyProcessingTimes); 444 populateProcessingTimeMap(modifyDNProcessingTimes); 445 populateProcessingTimeMap(searchProcessingTimes); 446 } 447 448 449 450 /** 451 * Retrieves the name for this tool. 452 * 453 * @return The name for this tool. 454 */ 455 @Override() 456 @NotNull() 457 public String getToolName() 458 { 459 return "summarize-access-log"; 460 } 461 462 463 464 /** 465 * Retrieves the description for this tool. 466 * 467 * @return The description for this tool. 468 */ 469 @Override() 470 @NotNull() 471 public String getToolDescription() 472 { 473 return "Examine one or more access log files from Ping Identity, " + 474 "UnboundID, or Nokia/Alcatel-Lucent 8661 server products to display " + 475 "a number of metrics about operations processed within the server."; 476 } 477 478 479 480 /** 481 * Retrieves the version string for this tool. 482 * 483 * @return The version string for this tool. 484 */ 485 @Override() 486 @NotNull() 487 public String getToolVersion() 488 { 489 return Version.NUMERIC_VERSION_STRING; 490 } 491 492 493 494 /** 495 * Retrieves the minimum number of unnamed trailing arguments that are 496 * required. 497 * 498 * @return One, to indicate that at least one trailing argument (representing 499 * the path to an access log file) must be provided. 500 */ 501 @Override() 502 public int getMinTrailingArguments() 503 { 504 return 1; 505 } 506 507 508 509 /** 510 * Retrieves the maximum number of unnamed trailing arguments that may be 511 * provided for this tool. 512 * 513 * @return The maximum number of unnamed trailing arguments that may be 514 * provided for this tool. 515 */ 516 @Override() 517 public int getMaxTrailingArguments() 518 { 519 return -1; 520 } 521 522 523 524 /** 525 * Retrieves a placeholder string that should be used for trailing arguments 526 * in the usage information for this tool. 527 * 528 * @return A placeholder string that should be used for trailing arguments in 529 * the usage information for this tool. 530 */ 531 @Override() 532 @NotNull() 533 public String getTrailingArgumentsPlaceholder() 534 { 535 return "{path}"; 536 } 537 538 539 540 /** 541 * Indicates whether this tool should provide support for an interactive mode, 542 * in which the tool offers a mode in which the arguments can be provided in 543 * a text-driven menu rather than requiring them to be given on the command 544 * line. If interactive mode is supported, it may be invoked using the 545 * "--interactive" argument. Alternately, if interactive mode is supported 546 * and {@link #defaultsToInteractiveMode()} returns {@code true}, then 547 * interactive mode may be invoked by simply launching the tool without any 548 * arguments. 549 * 550 * @return {@code true} if this tool supports interactive mode, or 551 * {@code false} if not. 552 */ 553 @Override() 554 public boolean supportsInteractiveMode() 555 { 556 return true; 557 } 558 559 560 561 /** 562 * Indicates whether this tool defaults to launching in interactive mode if 563 * the tool is invoked without any command-line arguments. This will only be 564 * used if {@link #supportsInteractiveMode()} returns {@code true}. 565 * 566 * @return {@code true} if this tool defaults to using interactive mode if 567 * launched without any command-line arguments, or {@code false} if 568 * not. 569 */ 570 @Override() 571 public boolean defaultsToInteractiveMode() 572 { 573 return true; 574 } 575 576 577 578 /** 579 * Indicates whether this tool should provide arguments for redirecting output 580 * to a file. If this method returns {@code true}, then the tool will offer 581 * an "--outputFile" argument that will specify the path to a file to which 582 * all standard output and standard error content will be written, and it will 583 * also offer a "--teeToStandardOut" argument that can only be used if the 584 * "--outputFile" argument is present and will cause all output to be written 585 * to both the specified output file and to standard output. 586 * 587 * @return {@code true} if this tool should provide arguments for redirecting 588 * output to a file, or {@code false} if not. 589 */ 590 @Override() 591 protected boolean supportsOutputFile() 592 { 593 return true; 594 } 595 596 597 598 /** 599 * Indicates whether this tool supports the use of a properties file for 600 * specifying default values for arguments that aren't specified on the 601 * command line. 602 * 603 * @return {@code true} if this tool supports the use of a properties file 604 * for specifying default values for arguments that aren't specified 605 * on the command line, or {@code false} if not. 606 */ 607 @Override() 608 public boolean supportsPropertiesFile() 609 { 610 return true; 611 } 612 613 614 615 /** 616 * Adds the command-line arguments supported for use with this tool to the 617 * provided argument parser. The tool may need to retain references to the 618 * arguments (and/or the argument parser, if trailing arguments are allowed) 619 * to it in order to obtain their values for use in later processing. 620 * 621 * @param parser The argument parser to which the arguments are to be added. 622 * 623 * @throws ArgumentException If a problem occurs while adding any of the 624 * tool-specific arguments to the provided 625 * argument parser. 626 */ 627 @Override() 628 public void addToolArguments(@NotNull final ArgumentParser parser) 629 throws ArgumentException 630 { 631 // We need to save a reference to the argument parser so that we can get 632 // the trailing arguments later. 633 argumentParser = parser; 634 635 // Add an argument that makes it possible to read a JSON-formatted access 636 // log file. 637 String description = "Indicates that the log file contains " + 638 "JSON-formatted log messages rather than text-formatted messages."; 639 json = new BooleanArgument(null, "json", description); 640 parser.addArgument(json); 641 642 643 // Add an argument that makes it possible to read a compressed log file. 644 // Note that this argument is no longer needed for dealing with compressed 645 // files, since the tool will automatically detect whether a file is 646 // compressed. However, the argument is still provided for the purpose of 647 // backward compatibility. 648 description = "Indicates that the log file is compressed."; 649 isCompressed = new BooleanArgument('c', "isCompressed", description); 650 isCompressed.addLongIdentifier("is-compressed", true); 651 isCompressed.addLongIdentifier("compressed", true); 652 isCompressed.setHidden(true); 653 parser.addArgument(isCompressed); 654 655 656 // Add an argument that indicates that the tool should read the encryption 657 // passphrase from a file. 658 description = "Indicates that the log file is encrypted and that the " + 659 "encryption passphrase is contained in the specified file. If " + 660 "the log data is encrypted and this argument is not provided, then " + 661 "the tool will interactively prompt for the encryption passphrase."; 662 encryptionPassphraseFile = new FileArgument(null, 663 "encryptionPassphraseFile", false, 1, null, description, true, true, 664 true, false); 665 encryptionPassphraseFile.addLongIdentifier("encryption-passphrase-file", 666 true); 667 encryptionPassphraseFile.addLongIdentifier("encryptionPasswordFile", true); 668 encryptionPassphraseFile.addLongIdentifier("encryption-password-file", 669 true); 670 parser.addArgument(encryptionPassphraseFile); 671 672 673 // Add an argument that indicates the number of values to display for each 674 // item being summarized. 675 description = "The number of values to display for each item being " + 676 "summarized. A value of zero indicates that all items should be " + 677 "displayed. If this is not provided, a default value of 20 will " + 678 "be used."; 679 reportCount = new IntegerArgument(null, "reportCount", false, 0, null, 680 description, 0, Integer.MAX_VALUE, 20); 681 reportCount.addLongIdentifier("report-count", true); 682 reportCount.addLongIdentifier("maximumCount", true); 683 reportCount.addLongIdentifier("maximum-count", true); 684 reportCount.addLongIdentifier("maxCount", true); 685 reportCount.addLongIdentifier("max-count", true); 686 reportCount.addLongIdentifier("count", true); 687 parser.addArgument(reportCount); 688 689 690 // Add an argument that indicates that the output should not be anonymized. 691 description = "Do not anonymize the output, but include actual attribute " + 692 "values in filters and DNs. This will also have the effect of " + 693 "de-generifying those values, so output including the most common " + 694 "filters and DNs in some category will be specific instances of " + 695 "those filters and DNs instead of generic patterns."; 696 doNotAnonymize = new BooleanArgument(null, "doNotAnonymize", 1, 697 description); 698 doNotAnonymize.addLongIdentifier("do-not-anonymize", true); 699 doNotAnonymize.addLongIdentifier("deAnonymize", true); 700 doNotAnonymize.addLongIdentifier("de-anonymize", true); 701 parser.addArgument(doNotAnonymize); 702 } 703 704 705 706 /** 707 * Performs any necessary processing that should be done to ensure that the 708 * provided set of command-line arguments were valid. This method will be 709 * called after the basic argument parsing has been performed and immediately 710 * before the {@link #doToolProcessing} method is invoked. 711 * 712 * @throws ArgumentException If there was a problem with the command-line 713 * arguments provided to this program. 714 */ 715 @Override() 716 public void doExtendedArgumentValidation() 717 throws ArgumentException 718 { 719 // Make sure that at least one access log file path was provided. 720 final List<String> trailingArguments = 721 argumentParser.getTrailingArguments(); 722 if ((trailingArguments == null) || trailingArguments.isEmpty()) 723 { 724 throw new ArgumentException("No access log file paths were provided."); 725 } 726 } 727 728 729 730 /** 731 * Performs the core set of processing for this tool. 732 * 733 * @return A result code that indicates whether the processing completed 734 * successfully. 735 */ 736 @Override() 737 @NotNull() 738 public ResultCode doToolProcessing() 739 { 740 int displayCount = reportCount.getValue(); 741 if (displayCount <= 0) 742 { 743 displayCount = Integer.MAX_VALUE; 744 } 745 746 String encryptionPassphrase = null; 747 if (encryptionPassphraseFile.isPresent()) 748 { 749 try 750 { 751 encryptionPassphrase = ToolUtils.readEncryptionPassphraseFromFile( 752 encryptionPassphraseFile.getValue()); 753 } 754 catch (final LDAPException e) 755 { 756 Debug.debugException(e); 757 err(e.getMessage()); 758 return e.getResultCode(); 759 } 760 } 761 762 763 long logLines = 0L; 764 for (final String path : argumentParser.getTrailingArguments()) 765 { 766 final File f = new File(path); 767 out("Examining access log ", f.getAbsolutePath()); 768 AccessLogReader reader = null; 769 InputStream inputStream = null; 770 try 771 { 772 inputStream = new FileInputStream(f); 773 774 final ObjectPair<InputStream,String> p = 775 ToolUtils.getPossiblyPassphraseEncryptedInputStream(inputStream, 776 encryptionPassphrase, 777 (! encryptionPassphraseFile.isPresent()), 778 "Log file '" + path + "' is encrypted. Please enter the " + 779 "encryption passphrase:", 780 "ERROR: The provided passphrase was incorrect.", 781 getOut(), getErr()); 782 inputStream = p.getFirst(); 783 if ((p.getSecond() != null) && (encryptionPassphrase == null)) 784 { 785 encryptionPassphrase = p.getSecond(); 786 } 787 788 if (isCompressed.isPresent()) 789 { 790 inputStream = new GZIPInputStream(inputStream); 791 } 792 else 793 { 794 inputStream = 795 ToolUtils.getPossiblyGZIPCompressedInputStream(inputStream); 796 } 797 798 if (json.isPresent()) 799 { 800 reader = new JSONAccessLogReader(inputStream); 801 } 802 else 803 { 804 reader = new TextFormattedAccessLogReader(inputStream); 805 } 806 } 807 catch (final Exception e) 808 { 809 Debug.debugException(e); 810 err("Unable to open access log file ", f.getAbsolutePath(), ": ", 811 StaticUtils.getExceptionMessage(e)); 812 return ResultCode.LOCAL_ERROR; 813 } 814 finally 815 { 816 if ((reader == null) && (inputStream != null)) 817 { 818 try 819 { 820 inputStream.close(); 821 } 822 catch (final Exception e) 823 { 824 Debug.debugException(e); 825 } 826 } 827 } 828 829 long startTime = 0L; 830 long stopTime = 0L; 831 832 while (true) 833 { 834 final AccessLogMessage msg; 835 try 836 { 837 msg = reader.readMessage(); 838 } 839 catch (final IOException ioe) 840 { 841 Debug.debugException(ioe); 842 err("Error reading from access log file ", f.getAbsolutePath(), 843 ": ", StaticUtils.getExceptionMessage(ioe)); 844 845 if ((ioe.getCause() != null) && 846 (ioe.getCause() instanceof BadPaddingException)) 847 { 848 err("This error is likely because the log is encrypted and the " + 849 "server still has the log file open. It is recommended " + 850 "that you only try to examine encrypted logs after they " + 851 "have been rotated. You can use the rotate-log tool to " + 852 "force a rotation at any time. Attempting to proceed with " + 853 "just the data that was successfully read."); 854 break; 855 } 856 else 857 { 858 return ResultCode.LOCAL_ERROR; 859 } 860 } 861 catch (final LogException le) 862 { 863 Debug.debugException(le); 864 err("Encountered an error while attempting to parse a line in" + 865 "access log file ", f.getAbsolutePath(), ": ", 866 StaticUtils.getExceptionMessage(le)); 867 continue; 868 } 869 870 if (msg == null) 871 { 872 break; 873 } 874 875 logLines++; 876 stopTime = msg.getTimestamp().getTime(); 877 if (startTime == 0L) 878 { 879 startTime = stopTime; 880 } 881 882 switch (msg.getMessageType()) 883 { 884 case CONNECT: 885 processConnect((ConnectAccessLogMessage) msg); 886 break; 887 case SECURITY_NEGOTIATION: 888 processSecurityNegotiation( 889 (SecurityNegotiationAccessLogMessage) msg); 890 break; 891 case DISCONNECT: 892 processDisconnect((DisconnectAccessLogMessage) msg); 893 break; 894 case REQUEST: 895 switch (((OperationRequestAccessLogMessage) msg).getOperationType()) 896 { 897 case ABANDON: 898 processAbandonRequest((AbandonRequestAccessLogMessage) msg); 899 break; 900 case EXTENDED: 901 processExtendedRequest((ExtendedRequestAccessLogMessage) msg); 902 break; 903 case SEARCH: 904 processSearchRequest((SearchRequestAccessLogMessage) msg); 905 break; 906 case UNBIND: 907 processUnbindRequest((UnbindRequestAccessLogMessage) msg); 908 break; 909 } 910 break; 911 case RESULT: 912 switch (((OperationRequestAccessLogMessage) msg).getOperationType()) 913 { 914 case ADD: 915 processAddResult((AddResultAccessLogMessage) msg); 916 break; 917 case BIND: 918 processBindResult((BindResultAccessLogMessage) msg); 919 break; 920 case COMPARE: 921 processCompareResult((CompareResultAccessLogMessage) msg); 922 break; 923 case DELETE: 924 processDeleteResult((DeleteResultAccessLogMessage) msg); 925 break; 926 case EXTENDED: 927 processExtendedResult((ExtendedResultAccessLogMessage) msg); 928 break; 929 case MODIFY: 930 processModifyResult((ModifyResultAccessLogMessage) msg); 931 break; 932 case MODDN: 933 processModifyDNResult((ModifyDNResultAccessLogMessage) msg); 934 break; 935 case SEARCH: 936 processSearchResult((SearchResultAccessLogMessage) msg); 937 break; 938 } 939 break; 940 941 case ASSURANCE_COMPLETE: 942 case CLIENT_CERTIFICATE: 943 case ENTRY_REBALANCING_REQUEST: 944 case ENTRY_REBALANCING_RESULT: 945 case FORWARD: 946 case FORWARD_FAILED: 947 case ENTRY: 948 case REFERENCE: 949 default: 950 // Nothing needs to be done for these message types. 951 } 952 } 953 954 try 955 { 956 reader.close(); 957 } 958 catch (final Exception e) 959 { 960 Debug.debugException(e); 961 } 962 logDurationMillis += (stopTime - startTime); 963 } 964 965 966 final int numFiles = argumentParser.getTrailingArguments().size(); 967 out(); 968 out("Examined ", logLines, " lines in ", numFiles, 969 ((numFiles == 1) ? " file" : " files"), 970 " covering a total duration of ", 971 StaticUtils.millisToHumanReadableDuration(logDurationMillis)); 972 if (logLines == 0) 973 { 974 return ResultCode.SUCCESS; 975 } 976 977 out(); 978 979 final double logDurationSeconds = logDurationMillis / 1_000.0; 980 final double connectsPerSecond = numConnects / logDurationSeconds; 981 final double disconnectsPerSecond = numDisconnects / logDurationSeconds; 982 983 out("Total connections established: ", numConnects, " (", 984 decimalFormat.format(connectsPerSecond), "/second)"); 985 out("Total disconnects: ", numDisconnects, " (", 986 decimalFormat.format(disconnectsPerSecond), "/second)"); 987 988 printCounts(clientAddresses, "Most common client addresses:", "address", 989 "addresses"); 990 991 printCounts(clientConnectionPolicies, 992 "Most common client connection policies:", "policy", "policies"); 993 994 printCounts(tlsProtocols, "Most common TLS protocol versions:", "version", 995 "versions"); 996 997 printCounts(tlsCipherSuites, "Most common TLS cipher suites:", 998 "cipher suite", "cipher suites"); 999 1000 printCounts(disconnectReasons, "Most common disconnect reasons:", "reason", 1001 "reasons"); 1002 1003 final long totalOps = numAbandons + numAdds + numBinds + numCompares + 1004 numDeletes + numExtended + numModifies + numModifyDNs + numSearches + 1005 numUnbinds; 1006 if (totalOps > 0) 1007 { 1008 final double percentAbandon = 100.0 * numAbandons / totalOps; 1009 final double percentAdd = 100.0 * numAdds / totalOps; 1010 final double percentBind = 100.0 * numBinds / totalOps; 1011 final double percentCompare = 100.0 * numCompares / totalOps; 1012 final double percentDelete = 100.0 * numDeletes / totalOps; 1013 final double percentExtended = 100.0 * numExtended / totalOps; 1014 final double percentModify = 100.0 * numModifies / totalOps; 1015 final double percentModifyDN = 100.0 * numModifyDNs / totalOps; 1016 final double percentSearch = 100.0 * numSearches / totalOps; 1017 final double percentUnbind = 100.0 * numUnbinds / totalOps; 1018 1019 final double abandonsPerSecond = numAbandons / logDurationSeconds; 1020 final double addsPerSecond = numAdds / logDurationSeconds; 1021 final double bindsPerSecond = numBinds / logDurationSeconds; 1022 final double comparesPerSecond = numCompares / logDurationSeconds; 1023 final double deletesPerSecond = numDeletes / logDurationSeconds; 1024 final double extendedPerSecond = numExtended / logDurationSeconds; 1025 final double modifiesPerSecond = numModifies / logDurationSeconds; 1026 final double modifyDNsPerSecond = numModifyDNs / logDurationSeconds; 1027 final double searchesPerSecond = numSearches / logDurationSeconds; 1028 final double unbindsPerSecond = numUnbinds / logDurationSeconds; 1029 1030 out(); 1031 out("Total operations examined: ", totalOps); 1032 out("Abandon operations examined: ", numAbandons, " (", 1033 decimalFormat.format(percentAbandon), "%, ", 1034 decimalFormat.format(abandonsPerSecond), "/second)"); 1035 out("Add operations examined: ", numAdds, " (", 1036 decimalFormat.format(percentAdd), "%, ", 1037 decimalFormat.format(addsPerSecond), "/second)"); 1038 out("Bind operations examined: ", numBinds, " (", 1039 decimalFormat.format(percentBind), "%, ", 1040 decimalFormat.format(bindsPerSecond), "/second)"); 1041 out("Compare operations examined: ", numCompares, " (", 1042 decimalFormat.format(percentCompare), "%, ", 1043 decimalFormat.format(comparesPerSecond), "/second)"); 1044 out("Delete operations examined: ", numDeletes, " (", 1045 decimalFormat.format(percentDelete), "%, ", 1046 decimalFormat.format(deletesPerSecond), "/second)"); 1047 out("Extended operations examined: ", numExtended, " (", 1048 decimalFormat.format(percentExtended), "%, ", 1049 decimalFormat.format(extendedPerSecond), "/second)"); 1050 out("Modify operations examined: ", numModifies, " (", 1051 decimalFormat.format(percentModify), "%, ", 1052 decimalFormat.format(modifiesPerSecond), "/second)"); 1053 out("Modify DN operations examined: ", numModifyDNs, " (", 1054 decimalFormat.format(percentModifyDN), "%, ", 1055 decimalFormat.format(modifyDNsPerSecond), "/second)"); 1056 out("Search operations examined: ", numSearches, " (", 1057 decimalFormat.format(percentSearch), "%, ", 1058 decimalFormat.format(searchesPerSecond), "/second)"); 1059 out("Unbind operations examined: ", numUnbinds, " (", 1060 decimalFormat.format(percentUnbind), "%, ", 1061 decimalFormat.format(unbindsPerSecond), "/second)"); 1062 1063 final double totalProcessingDuration = addProcessingDuration + 1064 bindProcessingDuration + compareProcessingDuration + 1065 deleteProcessingDuration + extendedProcessingDuration + 1066 modifyProcessingDuration + modifyDNProcessingDuration + 1067 searchProcessingDuration; 1068 1069 out(); 1070 out("Average operation processing duration: ", 1071 decimalFormat.format(totalProcessingDuration / totalOps), "ms"); 1072 1073 if (numAdds > 0) 1074 { 1075 out("Average add operation processing duration: ", 1076 decimalFormat.format(addProcessingDuration / numAdds), "ms"); 1077 } 1078 1079 if (numBinds > 0) 1080 { 1081 out("Average bind operation processing duration: ", 1082 decimalFormat.format(bindProcessingDuration / numBinds), "ms"); 1083 } 1084 1085 if (numCompares > 0) 1086 { 1087 out("Average compare operation processing duration: ", 1088 decimalFormat.format(compareProcessingDuration / numCompares), 1089 "ms"); 1090 } 1091 1092 if (numDeletes > 0) 1093 { 1094 out("Average delete operation processing duration: ", 1095 decimalFormat.format(deleteProcessingDuration / numDeletes), "ms"); 1096 } 1097 1098 if (numExtended > 0) 1099 { 1100 out("Average extended operation processing duration: ", 1101 decimalFormat.format(extendedProcessingDuration / numExtended), 1102 "ms"); 1103 } 1104 1105 if (numModifies > 0) 1106 { 1107 out("Average modify operation processing duration: ", 1108 decimalFormat.format(modifyProcessingDuration / numModifies), "ms"); 1109 } 1110 1111 if (numModifyDNs > 0) 1112 { 1113 out("Average modify DN operation processing duration: ", 1114 decimalFormat.format(modifyDNProcessingDuration / numModifyDNs), 1115 "ms"); 1116 } 1117 1118 if (numSearches > 0) 1119 { 1120 out("Average search operation processing duration: ", 1121 decimalFormat.format(searchProcessingDuration / numSearches), "ms"); 1122 } 1123 1124 printProcessingTimeHistogram("add", numAdds, addProcessingTimes); 1125 printProcessingTimeHistogram("bind", numBinds, bindProcessingTimes); 1126 printProcessingTimeHistogram("compare", numCompares, 1127 compareProcessingTimes); 1128 printProcessingTimeHistogram("delete", numDeletes, deleteProcessingTimes); 1129 printProcessingTimeHistogram("extended", numExtended, 1130 extendedProcessingTimes); 1131 printProcessingTimeHistogram("modify", numModifies, 1132 modifyProcessingTimes); 1133 printProcessingTimeHistogram("modify DN", numModifyDNs, 1134 modifyDNProcessingTimes); 1135 printProcessingTimeHistogram("search", numSearches, 1136 searchProcessingTimes); 1137 1138 printResultCodeCounts(addResultCodes, "add"); 1139 printResultCodeCounts(bindResultCodes, "bind"); 1140 printResultCodeCounts(compareResultCodes, "compare"); 1141 printResultCodeCounts(deleteResultCodes, "delete"); 1142 printResultCodeCounts(extendedResultCodes, "extended"); 1143 printResultCodeCounts(modifyResultCodes, "modify"); 1144 printResultCodeCounts(modifyDNResultCodes, "modify DN"); 1145 printResultCodeCounts(searchResultCodes, "search"); 1146 1147 printCounts(successfulBindDNs, 1148 "Most common bind DNs used in successful authentication attempts:", 1149 "DN", "DNs"); 1150 printCounts(failedBindDNs, 1151 "Most common bind DNs used in failed authentication attempts:", 1152 "DN", "DNs"); 1153 printCounts(authenticationTypes, "Most common authentication types:", 1154 "authentication type", "authentication types"); 1155 1156 long numResultsWithAuthzID = 0L; 1157 for (final AtomicLong l : authzDNs.values()) 1158 { 1159 numResultsWithAuthzID += l.get(); 1160 } 1161 1162 out(); 1163 final double percentWithAuthzID = 1164 100.0 * numResultsWithAuthzID / totalOps; 1165 out("Number of operations with an alternate authorization identity: ", 1166 numResultsWithAuthzID, " (", 1167 decimalFormat.format(percentWithAuthzID), "%)"); 1168 1169 printCounts(authzDNs, "Most common alternate authorization identity DNs:", 1170 "DN", "DNs"); 1171 1172 if (! extendedOperations.isEmpty()) 1173 { 1174 final List<ObjectPair<String,Long>> extOpCounts = new ArrayList<>(); 1175 final AtomicLong skippedWithSameCount = new AtomicLong(0L); 1176 final AtomicLong skippedWithLowerCount = new AtomicLong(0L); 1177 getMostCommonElements(extendedOperations, extOpCounts, displayCount, 1178 skippedWithSameCount, skippedWithLowerCount); 1179 1180 out(); 1181 out("Most common extended operation types:"); 1182 1183 long count = -1L; 1184 for (final ObjectPair<String,Long> p : extOpCounts) 1185 { 1186 count = p.getSecond(); 1187 final double percent = 100.0 * count / numExtended; 1188 1189 final String oid = p.getFirst(); 1190 final String name = extendedOperationOIDsToNames.get(oid); 1191 if (name == null) 1192 { 1193 out(p.getFirst(), ": ", p.getSecond(), " (", 1194 decimalFormat.format(percent), "%)"); 1195 } 1196 else 1197 { 1198 out(p.getFirst(), " (", name, "): ", p.getSecond(), " (", 1199 decimalFormat.format(percent), "%)"); 1200 } 1201 } 1202 1203 if (skippedWithSameCount.get() > 0L) 1204 { 1205 out("{ Skipped " + skippedWithSameCount.get() + 1206 " additional extended " + 1207 getSingularOrPlural(skippedWithSameCount.get(), "operation", 1208 "operations") + 1209 " with a count of " + count + " }"); 1210 } 1211 1212 if (skippedWithLowerCount.get() > 0L) 1213 { 1214 out("{ Skipped " + skippedWithLowerCount.get() + 1215 " additional extended " + 1216 getSingularOrPlural(skippedWithLowerCount.get(), "operation", 1217 "operations") + 1218 " with a count that is less than " + count + " }"); 1219 } 1220 } 1221 1222 out(); 1223 out("Number of unindexed search attempts: ", numUnindexedAttempts); 1224 out("Number of successfully-completed unindexed searches: ", 1225 numUnindexedSuccessful); 1226 out("Number of failed unindexed searches: ", numUnindexedFailed); 1227 1228 printCounts(unindexedFilters, "Most common unindexed search filters:", 1229 "filter", "filters"); 1230 1231 if (! searchScopes.isEmpty()) 1232 { 1233 final List<ObjectPair<SearchScope,Long>> scopeCounts = 1234 new ArrayList<>(); 1235 final AtomicLong skippedWithSameCount = new AtomicLong(0L); 1236 final AtomicLong skippedWithLowerCount = new AtomicLong(0L); 1237 getMostCommonElements(searchScopes, scopeCounts, displayCount, 1238 skippedWithSameCount, skippedWithLowerCount); 1239 1240 out(); 1241 out("Most common search scopes:"); 1242 1243 long count = -1L; 1244 for (final ObjectPair<SearchScope,Long> p : scopeCounts) 1245 { 1246 count = p.getSecond(); 1247 final double percent = 100.0 * count / numSearches; 1248 out(p.getFirst().getName().toLowerCase(), " (", 1249 p.getFirst().intValue(), "): ", p.getSecond(), " (", 1250 decimalFormat.format(percent), "%)"); 1251 } 1252 1253 if (skippedWithSameCount.get() > 0L) 1254 { 1255 out("{ Skipped " + skippedWithSameCount.get() + " additional " + 1256 getSingularOrPlural(skippedWithSameCount.get(), "scope", 1257 "scopes") + 1258 " with a count of " + count + " }"); 1259 } 1260 1261 if (skippedWithLowerCount.get() > 0L) 1262 { 1263 out("{ Skipped " + skippedWithLowerCount.get() + " additional " + 1264 getSingularOrPlural(skippedWithLowerCount.get(), "scope", 1265 "scopes") + 1266 " with a count that is less than " + count + " }"); 1267 } 1268 } 1269 1270 if (! searchEntryCounts.isEmpty()) 1271 { 1272 final List<ObjectPair<Long,Long>> entryCounts = new ArrayList<>(); 1273 final AtomicLong skippedWithSameCount = new AtomicLong(0L); 1274 final AtomicLong skippedWithLowerCount = new AtomicLong(0L); 1275 getMostCommonElements(searchEntryCounts, entryCounts, displayCount, 1276 skippedWithSameCount, skippedWithLowerCount); 1277 1278 out(); 1279 out("Most common search entry counts:"); 1280 1281 long count = -1L; 1282 for (final ObjectPair<Long,Long> p : entryCounts) 1283 { 1284 count = p.getSecond(); 1285 final double percent = 100.0 * count / numSearches; 1286 out(p.getFirst(), " matching ", 1287 getSingularOrPlural(p.getFirst(), "entry", "entries"), 1288 ": ", p.getSecond(), " (", decimalFormat.format(percent), "%)"); 1289 } 1290 1291 if (skippedWithSameCount.get() > 0L) 1292 { 1293 out("{ Skipped " + skippedWithSameCount.get() + " additional entry " + 1294 getSingularOrPlural(skippedWithSameCount.get(), "count", 1295 "counts") + 1296 " with a count of " + count + " }"); 1297 } 1298 1299 if (skippedWithLowerCount.get() > 0L) 1300 { 1301 out("{ Skipped " + skippedWithLowerCount.get() + 1302 " additional entry " + 1303 getSingularOrPlural(skippedWithLowerCount.get(), "count", 1304 "counts") + 1305 " with a count that is less than " + count + " }"); 1306 } 1307 } 1308 1309 printCounts(searchBaseDNs, 1310 "Most common base DNs for searches with a non-base scope:", 1311 "base DN", "base DNs"); 1312 1313 printCounts(filterTypes, 1314 "Most common filters for searches with a non-base scope:", 1315 "filter", "filters"); 1316 1317 if (numSearches > 0L) 1318 { 1319 long numSearchesMatchingNoEntries = 0L; 1320 for (final AtomicLong l : noEntryFilters.values()) 1321 { 1322 numSearchesMatchingNoEntries += l.get(); 1323 } 1324 1325 out(); 1326 final double noEntryPercent = 1327 100.0 * numSearchesMatchingNoEntries / numSearches; 1328 out("Number of searches matching no entries: ", 1329 numSearchesMatchingNoEntries, " (", 1330 decimalFormat.format(noEntryPercent), "%)"); 1331 1332 printCounts(noEntryFilters, 1333 "Most common filters for searches matching no entries:", 1334 "filter", "filters"); 1335 1336 1337 long numSearchesMatchingOneEntry = 0L; 1338 for (final AtomicLong l : oneEntryFilters.values()) 1339 { 1340 numSearchesMatchingOneEntry += l.get(); 1341 } 1342 1343 out(); 1344 final double oneEntryPercent = 1345 100.0 * numSearchesMatchingOneEntry / numSearches; 1346 out("Number of searches matching one entry: ", 1347 numSearchesMatchingOneEntry, " (", 1348 decimalFormat.format(oneEntryPercent), "%)"); 1349 1350 printCounts(oneEntryFilters, 1351 "Most common filters for searches matching one entry:", 1352 "filter", "filters"); 1353 1354 1355 long numSearchesMatchingMultipleEntries = 0L; 1356 for (final AtomicLong l : multiEntryFilters.values()) 1357 { 1358 numSearchesMatchingMultipleEntries += l.get(); 1359 } 1360 1361 out(); 1362 final double multiEntryPercent = 1363 100.0 * numSearchesMatchingMultipleEntries / numSearches; 1364 out("Number of searches matching multiple entries: ", 1365 numSearchesMatchingMultipleEntries, " (", 1366 decimalFormat.format(multiEntryPercent), "%)"); 1367 1368 printCounts(multiEntryFilters, 1369 "Most common filters for searches matching multiple entries:", 1370 "filter", "filters"); 1371 } 1372 } 1373 1374 if (! mostExpensiveFilters.isEmpty()) 1375 { 1376 final List<ObjectPair<String,Long>> filterDurations = new ArrayList<>(); 1377 final AtomicLong skippedWithSameCount = new AtomicLong(0L); 1378 final AtomicLong skippedWithLowerCount = new AtomicLong(0L); 1379 getMostCommonElements(mostExpensiveFilters, filterDurations, 1380 displayCount, skippedWithSameCount, skippedWithLowerCount); 1381 1382 out(); 1383 out("Filters for searches with the longest processing times:"); 1384 1385 String durationStr = ""; 1386 for (final ObjectPair<String,Long> p : filterDurations) 1387 { 1388 final long durationMicros = p.getSecond(); 1389 final double durationMillis = durationMicros / 1_000.0; 1390 durationStr = decimalFormat.format(durationMillis) + " ms"; 1391 out(p.getFirst(), ": ", durationStr); 1392 } 1393 1394 if (skippedWithSameCount.get() > 0L) 1395 { 1396 out("{ Skipped " + skippedWithSameCount.get() + " additional " + 1397 getSingularOrPlural(skippedWithSameCount.get(), "filter", 1398 "filters") + 1399 " with a duration of " + durationStr + " }"); 1400 } 1401 1402 if (skippedWithLowerCount.get() > 0L) 1403 { 1404 out("{ Skipped " + skippedWithLowerCount.get() + " additional " + 1405 getSingularOrPlural(skippedWithLowerCount.get(), "filter", 1406 "filters") + 1407 " with a duration that is less than " + durationStr + " }"); 1408 } 1409 } 1410 1411 final long totalUncached = numUncachedAdds + numUncachedBinds + 1412 numUncachedCompares + numUncachedDeletes + numUncachedExtended + 1413 numUncachedModifies + numUncachedModifyDNs + numUncachedSearches; 1414 if (totalUncached > 0L) 1415 { 1416 out(); 1417 out("Operations accessing uncached data:"); 1418 printUncached("Add", numUncachedAdds, numAdds); 1419 printUncached("Bind", numUncachedBinds, numBinds); 1420 printUncached("Compare", numUncachedCompares, numCompares); 1421 printUncached("Delete", numUncachedDeletes, numDeletes); 1422 printUncached("Extended", numUncachedExtended, numExtended); 1423 printUncached("Modify", numUncachedModifies, numModifies); 1424 printUncached("Modify DN", numUncachedModifyDNs, numModifyDNs); 1425 printUncached("Search", numUncachedSearches, numSearches); 1426 } 1427 1428 1429 return ResultCode.SUCCESS; 1430 } 1431 1432 1433 1434 /** 1435 * Retrieves a set of information that may be used to generate example usage 1436 * information. Each element in the returned map should consist of a map 1437 * between an example set of arguments and a string that describes the 1438 * behavior of the tool when invoked with that set of arguments. 1439 * 1440 * @return A set of information that may be used to generate example usage 1441 * information. It may be {@code null} or empty if no example usage 1442 * information is available. 1443 */ 1444 @Override() 1445 @NotNull() 1446 public LinkedHashMap<String[],String> getExampleUsages() 1447 { 1448 final LinkedHashMap<String[],String> examples = 1449 new LinkedHashMap<>(StaticUtils.computeMapCapacity(1)); 1450 1451 final String[] args = 1452 { 1453 "/ds/logs/access" 1454 }; 1455 final String description = 1456 "Analyze the contents of the /ds/logs/access access log file."; 1457 examples.put(args, description); 1458 1459 return examples; 1460 } 1461 1462 1463 1464 /** 1465 * Populates the provided processing time map with an initial set of values. 1466 * 1467 * @param m The processing time map to be populated. 1468 */ 1469 private static void populateProcessingTimeMap( 1470 @NotNull final HashMap<Long,AtomicLong> m) 1471 { 1472 m.put(1L, new AtomicLong(0L)); 1473 m.put(2L, new AtomicLong(0L)); 1474 m.put(3L, new AtomicLong(0L)); 1475 m.put(5L, new AtomicLong(0L)); 1476 m.put(10L, new AtomicLong(0L)); 1477 m.put(20L, new AtomicLong(0L)); 1478 m.put(30L, new AtomicLong(0L)); 1479 m.put(50L, new AtomicLong(0L)); 1480 m.put(100L, new AtomicLong(0L)); 1481 m.put(1_000L, new AtomicLong(0L)); 1482 m.put(2_000L, new AtomicLong(0L)); 1483 m.put(3_000L, new AtomicLong(0L)); 1484 m.put(5_000L, new AtomicLong(0L)); 1485 m.put(10_000L, new AtomicLong(0L)); 1486 m.put(20_000L, new AtomicLong(0L)); 1487 m.put(30_000L, new AtomicLong(0L)); 1488 m.put(60_000L, new AtomicLong(0L)); 1489 m.put(Long.MAX_VALUE, new AtomicLong(0L)); 1490 } 1491 1492 1493 1494 /** 1495 * Performs any necessary processing for a connect message. 1496 * 1497 * @param m The log message to be processed. 1498 */ 1499 private void processConnect(@NotNull final ConnectAccessLogMessage m) 1500 { 1501 numConnects++; 1502 1503 final String clientAddr = m.getSourceAddress(); 1504 if (clientAddr != null) 1505 { 1506 AtomicLong count = clientAddresses.get(clientAddr); 1507 if (count == null) 1508 { 1509 count = new AtomicLong(0L); 1510 clientAddresses.put(clientAddr, count); 1511 } 1512 count.incrementAndGet(); 1513 } 1514 1515 final String ccp = m.getClientConnectionPolicy(); 1516 if (ccp != null) 1517 { 1518 AtomicLong l = clientConnectionPolicies.get(ccp); 1519 if (l == null) 1520 { 1521 l = new AtomicLong(0L); 1522 clientConnectionPolicies.put(ccp, l); 1523 } 1524 l.incrementAndGet(); 1525 } 1526 } 1527 1528 1529 1530 /** 1531 * Performs any necessary processing for a security negotiation message. 1532 * 1533 * @param m The log message to be processed. 1534 */ 1535 private void processSecurityNegotiation( 1536 @NotNull final SecurityNegotiationAccessLogMessage m) 1537 { 1538 final String protocol = m.getProtocol(); 1539 if (protocol != null) 1540 { 1541 AtomicLong l = tlsProtocols.get(protocol); 1542 if (l == null) 1543 { 1544 l = new AtomicLong(0L); 1545 tlsProtocols.put(protocol, l); 1546 } 1547 l.incrementAndGet(); 1548 } 1549 1550 final String cipherSuite = m.getCipher(); 1551 if (cipherSuite != null) 1552 { 1553 AtomicLong l = tlsCipherSuites.get(cipherSuite); 1554 if (l == null) 1555 { 1556 l = new AtomicLong(0L); 1557 tlsCipherSuites.put(cipherSuite, l); 1558 } 1559 l.incrementAndGet(); 1560 } 1561 } 1562 1563 1564 1565 /** 1566 * Performs any necessary processing for a disconnect message. 1567 * 1568 * @param m The log message to be processed. 1569 */ 1570 private void processDisconnect(@NotNull final DisconnectAccessLogMessage m) 1571 { 1572 numDisconnects++; 1573 1574 final String reason = m.getDisconnectReason(); 1575 if (reason != null) 1576 { 1577 AtomicLong l = disconnectReasons.get(reason); 1578 if (l == null) 1579 { 1580 l = new AtomicLong(0L); 1581 disconnectReasons.put(reason, l); 1582 } 1583 l.incrementAndGet(); 1584 } 1585 } 1586 1587 1588 1589 /** 1590 * Performs any necessary processing for an abandon request message. 1591 * 1592 * @param m The log message to be processed. 1593 */ 1594 private void processAbandonRequest( 1595 @NotNull final AbandonRequestAccessLogMessage m) 1596 { 1597 numAbandons++; 1598 } 1599 1600 1601 1602 /** 1603 * Performs any necessary processing for an extended request message. 1604 * 1605 * @param m The log message to be processed. 1606 */ 1607 private void processExtendedRequest( 1608 @NotNull final ExtendedRequestAccessLogMessage m) 1609 { 1610 processedRequests.add(m.getConnectionID() + "-" + m.getOperationID()); 1611 processExtendedRequestInternal(m); 1612 } 1613 1614 1615 1616 /** 1617 * Performs the internal processing for an extended request message. 1618 * 1619 * @param m The log message to be processed. 1620 */ 1621 private void processExtendedRequestInternal( 1622 @NotNull final ExtendedRequestAccessLogMessage m) 1623 { 1624 final String oid = m.getRequestOID(); 1625 if (oid != null) 1626 { 1627 AtomicLong l = extendedOperations.get(oid); 1628 if (l == null) 1629 { 1630 l = new AtomicLong(0L); 1631 extendedOperations.put(oid, l); 1632 } 1633 l.incrementAndGet(); 1634 1635 final String requestType = m.getRequestType(); 1636 if ((requestType != null) && 1637 (! extendedOperationOIDsToNames.containsKey(oid))) 1638 { 1639 extendedOperationOIDsToNames.put(oid, requestType); 1640 } 1641 } 1642 } 1643 1644 1645 1646 /** 1647 * Performs any necessary processing for a search request message. 1648 * 1649 * @param m The log message to be processed. 1650 */ 1651 private void processSearchRequest( 1652 @NotNull final SearchRequestAccessLogMessage m) 1653 { 1654 processedRequests.add(m.getConnectionID() + "-" + m.getOperationID()); 1655 processSearchRequestInternal(m); 1656 } 1657 1658 1659 1660 /** 1661 * Performs any necessary processing for a search request message. 1662 * 1663 * @param m The log message to be processed. 1664 */ 1665 private void processSearchRequestInternal( 1666 @NotNull final SearchRequestAccessLogMessage m) 1667 { 1668 final SearchScope scope = m.getScope(); 1669 if (scope != null) 1670 { 1671 AtomicLong scopeCount = searchScopes.get(scope); 1672 if (scopeCount == null) 1673 { 1674 scopeCount = new AtomicLong(0L); 1675 searchScopes.put(scope, scopeCount); 1676 } 1677 scopeCount.incrementAndGet(); 1678 1679 if (! scope.equals(SearchScope.BASE)) 1680 { 1681 final String filterString = prepareFilter(m.getFilter()); 1682 if (filterString != null) 1683 { 1684 AtomicLong filterCount = filterTypes.get(filterString); 1685 if (filterCount == null) 1686 { 1687 filterCount = new AtomicLong(0L); 1688 filterTypes.put(filterString, filterCount); 1689 } 1690 filterCount.incrementAndGet(); 1691 1692 1693 final String baseDN = getDNString(m.getBaseDN()); 1694 if (baseDN != null) 1695 { 1696 AtomicLong baseDNCount = searchBaseDNs.get(baseDN); 1697 if (baseDNCount == null) 1698 { 1699 baseDNCount = new AtomicLong(0L); 1700 searchBaseDNs.put(baseDN, baseDNCount); 1701 } 1702 baseDNCount.incrementAndGet(); 1703 } 1704 } 1705 } 1706 } 1707 } 1708 1709 1710 1711 /** 1712 * Performs any necessary processing for an unbind request message. 1713 * 1714 * @param m The log message to be processed. 1715 */ 1716 private void processUnbindRequest( 1717 @NotNull final UnbindRequestAccessLogMessage m) 1718 { 1719 numUnbinds++; 1720 } 1721 1722 1723 1724 /** 1725 * Performs any necessary processing for an add result message. 1726 * 1727 * @param m The log message to be processed. 1728 */ 1729 private void processAddResult(@NotNull final AddResultAccessLogMessage m) 1730 { 1731 numAdds++; 1732 1733 updateResultCodeCount(m.getResultCode(), addResultCodes); 1734 addProcessingDuration += 1735 doubleValue(m.getProcessingTimeMillis(), addProcessingTimes); 1736 1737 final Boolean uncachedDataAccessed = m.getUncachedDataAccessed(); 1738 if ((uncachedDataAccessed != null) && uncachedDataAccessed) 1739 { 1740 numUncachedAdds++; 1741 } 1742 1743 updateAuthzCount(m.getAlternateAuthorizationDN()); 1744 } 1745 1746 1747 1748 /** 1749 * Performs any necessary processing for a bind result message. 1750 * 1751 * @param m The log message to be processed. 1752 */ 1753 private void processBindResult(@NotNull final BindResultAccessLogMessage m) 1754 { 1755 numBinds++; 1756 1757 if (m.getAuthenticationType() != null) 1758 { 1759 final String authType; 1760 switch (m.getAuthenticationType()) 1761 { 1762 case SIMPLE: 1763 authType = "Simple"; 1764 break; 1765 1766 case SASL: 1767 final String saslMechanism = m.getSASLMechanismName(); 1768 if (saslMechanism == null) 1769 { 1770 authType = "SASL {unknown mechanism}"; 1771 } 1772 else 1773 { 1774 authType = "SASL " + saslMechanism; 1775 } 1776 break; 1777 1778 case INTERNAL: 1779 authType = "Internal"; 1780 break; 1781 1782 default: 1783 authType = m.getAuthenticationType().name(); 1784 break; 1785 } 1786 1787 AtomicLong l = authenticationTypes.get(authType); 1788 if (l == null) 1789 { 1790 l = new AtomicLong(0L); 1791 authenticationTypes.put(authType, l); 1792 } 1793 l.incrementAndGet(); 1794 } 1795 1796 updateResultCodeCount(m.getResultCode(), bindResultCodes); 1797 bindProcessingDuration += 1798 doubleValue(m.getProcessingTimeMillis(), bindProcessingTimes); 1799 1800 String authenticationDN = getDNString(m.getAuthenticationDN()); 1801 if (m.getResultCode() == ResultCode.SUCCESS) 1802 { 1803 if (authenticationDN != null) 1804 { 1805 AtomicLong l = successfulBindDNs.get(authenticationDN); 1806 if (l == null) 1807 { 1808 l = new AtomicLong(0L); 1809 successfulBindDNs.put(authenticationDN, l); 1810 } 1811 l.incrementAndGet(); 1812 } 1813 1814 final String ccp = m.getClientConnectionPolicy(); 1815 if (ccp != null) 1816 { 1817 AtomicLong l = clientConnectionPolicies.get(ccp); 1818 if (l == null) 1819 { 1820 l = new AtomicLong(0L); 1821 clientConnectionPolicies.put(ccp, l); 1822 } 1823 l.incrementAndGet(); 1824 } 1825 } 1826 else if ((m.getResultCode() != ResultCode.SASL_BIND_IN_PROGRESS) && 1827 (m.getResultCode() != ResultCode.REFERRAL)) 1828 { 1829 if (authenticationDN == null) 1830 { 1831 authenticationDN = getDNString(m.getDN()); 1832 } 1833 1834 if (authenticationDN != null) 1835 { 1836 AtomicLong l = failedBindDNs.get(authenticationDN); 1837 if (l == null) 1838 { 1839 l = new AtomicLong(0L); 1840 failedBindDNs.put(authenticationDN, l); 1841 } 1842 l.incrementAndGet(); 1843 } 1844 } 1845 1846 final Boolean uncachedDataAccessed = m.getUncachedDataAccessed(); 1847 if ((uncachedDataAccessed != null) && uncachedDataAccessed) 1848 { 1849 numUncachedBinds++; 1850 } 1851 1852 updateAuthzCount(m.getAuthorizationDN()); 1853 } 1854 1855 1856 1857 /** 1858 * Performs any necessary processing for a compare result message. 1859 * 1860 * @param m The log message to be processed. 1861 */ 1862 private void processCompareResult( 1863 @NotNull final CompareResultAccessLogMessage m) 1864 { 1865 numCompares++; 1866 1867 updateResultCodeCount(m.getResultCode(), compareResultCodes); 1868 compareProcessingDuration += 1869 doubleValue(m.getProcessingTimeMillis(), compareProcessingTimes); 1870 1871 final Boolean uncachedDataAccessed = m.getUncachedDataAccessed(); 1872 if ((uncachedDataAccessed != null) && uncachedDataAccessed) 1873 { 1874 numUncachedCompares++; 1875 } 1876 1877 updateAuthzCount(m.getAlternateAuthorizationDN()); 1878 } 1879 1880 1881 1882 /** 1883 * Performs any necessary processing for a delete result message. 1884 * 1885 * @param m The log message to be processed. 1886 */ 1887 private void processDeleteResult( 1888 @NotNull final DeleteResultAccessLogMessage m) 1889 { 1890 numDeletes++; 1891 1892 updateResultCodeCount(m.getResultCode(), deleteResultCodes); 1893 deleteProcessingDuration += 1894 doubleValue(m.getProcessingTimeMillis(), deleteProcessingTimes); 1895 1896 final Boolean uncachedDataAccessed = m.getUncachedDataAccessed(); 1897 if ((uncachedDataAccessed != null) && uncachedDataAccessed) 1898 { 1899 numUncachedDeletes++; 1900 } 1901 1902 updateAuthzCount(m.getAlternateAuthorizationDN()); 1903 } 1904 1905 1906 1907 /** 1908 * Performs any necessary processing for an extended result message. 1909 * 1910 * @param m The log message to be processed. 1911 */ 1912 private void processExtendedResult( 1913 @NotNull final ExtendedResultAccessLogMessage m) 1914 { 1915 numExtended++; 1916 1917 final String id = m.getConnectionID() + "-" + m.getOperationID(); 1918 if (!processedRequests.remove(id)) 1919 { 1920 processExtendedRequestInternal(m); 1921 } 1922 1923 updateResultCodeCount(m.getResultCode(), extendedResultCodes); 1924 extendedProcessingDuration += 1925 doubleValue(m.getProcessingTimeMillis(), extendedProcessingTimes); 1926 1927 final String ccp = m.getClientConnectionPolicy(); 1928 if (ccp != null) 1929 { 1930 AtomicLong l = clientConnectionPolicies.get(ccp); 1931 if (l == null) 1932 { 1933 l = new AtomicLong(0L); 1934 clientConnectionPolicies.put(ccp, l); 1935 } 1936 l.incrementAndGet(); 1937 } 1938 1939 final Boolean uncachedDataAccessed = m.getUncachedDataAccessed(); 1940 if ((uncachedDataAccessed != null) && uncachedDataAccessed) 1941 { 1942 numUncachedExtended++; 1943 } 1944 } 1945 1946 1947 1948 /** 1949 * Performs any necessary processing for a modify result message. 1950 * 1951 * @param m The log message to be processed. 1952 */ 1953 private void processModifyResult( 1954 @NotNull final ModifyResultAccessLogMessage m) 1955 { 1956 numModifies++; 1957 1958 updateResultCodeCount(m.getResultCode(), modifyResultCodes); 1959 modifyProcessingDuration += 1960 doubleValue(m.getProcessingTimeMillis(), modifyProcessingTimes); 1961 1962 final Boolean uncachedDataAccessed = m.getUncachedDataAccessed(); 1963 if ((uncachedDataAccessed != null) && uncachedDataAccessed) 1964 { 1965 numUncachedModifies++; 1966 } 1967 1968 updateAuthzCount(m.getAlternateAuthorizationDN()); 1969 } 1970 1971 1972 1973 /** 1974 * Performs any necessary processing for a modify DN result message. 1975 * 1976 * @param m The log message to be processed. 1977 */ 1978 private void processModifyDNResult( 1979 @NotNull final ModifyDNResultAccessLogMessage m) 1980 { 1981 numModifyDNs++; 1982 1983 updateResultCodeCount(m.getResultCode(), modifyDNResultCodes); 1984 modifyDNProcessingDuration += 1985 doubleValue(m.getProcessingTimeMillis(), modifyDNProcessingTimes); 1986 1987 final Boolean uncachedDataAccessed = m.getUncachedDataAccessed(); 1988 if ((uncachedDataAccessed != null) && uncachedDataAccessed) 1989 { 1990 numUncachedModifyDNs++; 1991 } 1992 1993 updateAuthzCount(m.getAlternateAuthorizationDN()); 1994 } 1995 1996 1997 1998 /** 1999 * Performs any necessary processing for a search result message. 2000 * 2001 * @param m The log message to be processed. 2002 */ 2003 private void processSearchResult( 2004 @NotNull final SearchResultAccessLogMessage m) 2005 { 2006 numSearches++; 2007 2008 final String id = m.getConnectionID() + "-" + m.getOperationID(); 2009 if (! processedRequests.remove(id)) 2010 { 2011 processSearchRequestInternal(m); 2012 } 2013 2014 final ResultCode resultCode = m.getResultCode(); 2015 updateResultCodeCount(resultCode, searchResultCodes); 2016 searchProcessingDuration += 2017 doubleValue(m.getProcessingTimeMillis(), searchProcessingTimes); 2018 2019 final String filterString = prepareFilter(m.getFilter()); 2020 2021 final Long entryCount = m.getEntriesReturned(); 2022 if (entryCount != null) 2023 { 2024 AtomicLong l = searchEntryCounts.get(entryCount); 2025 if (l == null) 2026 { 2027 l = new AtomicLong(0L); 2028 searchEntryCounts.put(entryCount, l); 2029 } 2030 l.incrementAndGet(); 2031 2032 final Map<String,AtomicLong> filterCountMap; 2033 switch (entryCount.intValue()) 2034 { 2035 case 0: 2036 filterCountMap = noEntryFilters; 2037 break; 2038 case 1: 2039 filterCountMap = oneEntryFilters; 2040 break; 2041 default: 2042 filterCountMap = multiEntryFilters; 2043 break; 2044 } 2045 2046 if (filterString != null) 2047 { 2048 AtomicLong filterCount = filterCountMap.get(filterString); 2049 if (filterCount == null) 2050 { 2051 filterCount = new AtomicLong(0L); 2052 filterCountMap.put(filterString, filterCount); 2053 } 2054 filterCount.incrementAndGet(); 2055 } 2056 } 2057 2058 final Boolean isUnindexed = m.getUnindexed(); 2059 if ((isUnindexed != null) && isUnindexed) 2060 { 2061 numUnindexedAttempts++; 2062 if (resultCode == ResultCode.SUCCESS) 2063 { 2064 numUnindexedSuccessful++; 2065 } 2066 else 2067 { 2068 numUnindexedFailed++; 2069 } 2070 2071 if (filterString != null) 2072 { 2073 AtomicLong l = unindexedFilters.get(filterString); 2074 if (l == null) 2075 { 2076 l = new AtomicLong(0L); 2077 unindexedFilters.put(filterString, l); 2078 } 2079 l.incrementAndGet(); 2080 } 2081 } 2082 2083 final Boolean uncachedDataAccessed = m.getUncachedDataAccessed(); 2084 if ((uncachedDataAccessed != null) && uncachedDataAccessed) 2085 { 2086 numUncachedSearches++; 2087 } 2088 2089 updateAuthzCount(m.getAlternateAuthorizationDN()); 2090 2091 final Double processingTimeMillis = m.getProcessingTimeMillis(); 2092 if ((processingTimeMillis != null) && (filterString != null)) 2093 { 2094 final long processingTimeMicros = 2095 Math.round(processingTimeMillis * 1_000.0); 2096 2097 AtomicLong l = mostExpensiveFilters.get(filterString); 2098 if (l == null) 2099 { 2100 l = new AtomicLong(processingTimeMicros); 2101 mostExpensiveFilters.put(filterString, l); 2102 } 2103 else 2104 { 2105 final long previousProcessingTimeMicros = l.get(); 2106 if (processingTimeMicros > previousProcessingTimeMicros) 2107 { 2108 l.set(processingTimeMicros); 2109 } 2110 } 2111 } 2112 } 2113 2114 2115 2116 /** 2117 * Updates the count for the provided result code in the given map. 2118 * 2119 * @param rc The result code for which to update the count. 2120 * @param m The map used to hold counts by result code. 2121 */ 2122 private static void updateResultCodeCount(@Nullable final ResultCode rc, 2123 @NotNull final HashMap<ResultCode,AtomicLong> m) 2124 { 2125 if (rc == null) 2126 { 2127 return; 2128 } 2129 2130 AtomicLong l = m.get(rc); 2131 if (l == null) 2132 { 2133 l = new AtomicLong(0L); 2134 m.put(rc, l); 2135 } 2136 l.incrementAndGet(); 2137 } 2138 2139 2140 2141 /** 2142 * Retrieves the double value for the provided {@code Double} object. 2143 * 2144 * @param d The {@code Double} object for which to retrieve the value. 2145 * @param m The processing time histogram map to be updated. 2146 * 2147 * @return The double value of the provided {@code Double} object if it was 2148 * non-{@code null}, or 0.0 if it was {@code null}. 2149 */ 2150 private static double doubleValue(@Nullable final Double d, 2151 @NotNull final HashMap<Long,AtomicLong> m) 2152 { 2153 if (d == null) 2154 { 2155 return 0.0; 2156 } 2157 else 2158 { 2159 for (final Map.Entry<Long,AtomicLong> e : m.entrySet()) 2160 { 2161 if (d <= e.getKey()) 2162 { 2163 e.getValue().incrementAndGet(); 2164 break; 2165 } 2166 } 2167 2168 return d; 2169 } 2170 } 2171 2172 2173 2174 /** 2175 * Updates the provided list with the most frequently-occurring elements in 2176 * the provided map, paired with the number of times each value occurred. 2177 * 2178 * @param <K> The type of object used as the key for the 2179 * provided map. 2180 * @param countMap The map to be examined. It is expected that 2181 * the values of the map will be the count of 2182 * occurrences for the keys. 2183 * @param mostCommonElementList The list to which the values will be 2184 * updated. It must not be {@code null}, must 2185 * be empty, and must be updatable. 2186 * @param maxListSize The maximum number of items to add to the 2187 * provided list. It must be greater than 2188 * zero. 2189 * @param skippedWithSameCount A counter that will be incremented for each 2190 * map entry that is skipped with the same 2191 * count as a value that was not skipped. It 2192 * must not be {@code null} and must initially 2193 * be zero. 2194 * @param skippedWithLowerCount A counter that will be incremented for each 2195 * map entry that is skipped with a lower count 2196 * as the last value that was not skipped. It 2197 * must not be {@code null} and must initially 2198 * be zero. 2199 * 2200 * @return A list of the most frequently-occurring elements in the provided 2201 * map. 2202 */ 2203 @NotNull() 2204 private static <K> List<ObjectPair<K,Long>> getMostCommonElements( 2205 @NotNull final Map<K,AtomicLong> countMap, 2206 @NotNull final List<ObjectPair<K,Long>> mostCommonElementList, 2207 final int maxListSize, 2208 @NotNull final AtomicLong skippedWithSameCount, 2209 @NotNull final AtomicLong skippedWithLowerCount) 2210 { 2211 final TreeMap<Long,List<K>> reverseMap = 2212 new TreeMap<>(new ReverseComparator<Long>()); 2213 for (final Map.Entry<K,AtomicLong> e : countMap.entrySet()) 2214 { 2215 final Long count = e.getValue().get(); 2216 List<K> list = reverseMap.get(count); 2217 if (list == null) 2218 { 2219 list = new ArrayList<>(); 2220 reverseMap.put(count, list); 2221 } 2222 list.add(e.getKey()); 2223 } 2224 2225 for (final Map.Entry<Long,List<K>> e : reverseMap.entrySet()) 2226 { 2227 final Long l = e.getKey(); 2228 int numNotSkipped = 0; 2229 for (final K k : e.getValue()) 2230 { 2231 if (mostCommonElementList.size() >= maxListSize) 2232 { 2233 if (numNotSkipped > 0) 2234 { 2235 skippedWithSameCount.incrementAndGet(); 2236 } 2237 else 2238 { 2239 skippedWithLowerCount.incrementAndGet(); 2240 } 2241 } 2242 else 2243 { 2244 numNotSkipped++; 2245 mostCommonElementList.add(new ObjectPair<>(k, l)); 2246 } 2247 } 2248 } 2249 2250 return mostCommonElementList; 2251 } 2252 2253 2254 2255 /** 2256 * Updates the count of alternate authorization identities for the provided 2257 * DN. 2258 * 2259 * @param authzDN The DN of the alternate authorization identity that was 2260 * used. It may be {@code null} if no alternate 2261 * authorization identity was used. 2262 */ 2263 private void updateAuthzCount(@Nullable final String authzDN) 2264 { 2265 if (authzDN == null) 2266 { 2267 return; 2268 } 2269 2270 final String dnString = getDNString(authzDN); 2271 2272 AtomicLong l = authzDNs.get(dnString); 2273 if (l == null) 2274 { 2275 l = new AtomicLong(0L); 2276 authzDNs.put(dnString, l); 2277 } 2278 } 2279 2280 2281 2282 /** 2283 * Retrieves a string representation of the provided DN. It may either be 2284 * anonymized, using question marks in place of specific attribute values, or 2285 * it may be the actual string representation of the given DN. 2286 * 2287 * @param dn The DN for which to retrieve the string representation. 2288 * 2289 * @return A string representation of the provided DN, or {@code null} if the 2290 * given DN was {@code null}. 2291 */ 2292 @Nullable() 2293 private String getDNString(@Nullable final String dn) 2294 { 2295 if (dn == null) 2296 { 2297 return null; 2298 } 2299 2300 final DN parsedDN; 2301 try 2302 { 2303 parsedDN = new DN(dn); 2304 } 2305 catch (final Exception e) 2306 { 2307 Debug.debugException(e); 2308 return dn.toLowerCase(); 2309 } 2310 2311 if (parsedDN.isNullDN()) 2312 { 2313 return "{Null DN}"; 2314 } 2315 2316 if (doNotAnonymize.isPresent()) 2317 { 2318 return parsedDN.toNormalizedString(); 2319 } 2320 2321 final StringBuilder buffer = new StringBuilder(); 2322 final RDN[] rdns = parsedDN.getRDNs(); 2323 for (int i=0; i < rdns.length; i++) 2324 { 2325 if (i > 0) 2326 { 2327 buffer.append(','); 2328 } 2329 2330 final RDN rdn = rdns[i]; 2331 final String[] attributeNames = rdn.getAttributeNames(); 2332 for (int j=0; j < attributeNames.length; j++) 2333 { 2334 if (j > 0) 2335 { 2336 buffer.append('+'); 2337 } 2338 buffer.append(attributeNames[j].toLowerCase()); 2339 buffer.append("=?"); 2340 } 2341 } 2342 2343 return buffer.toString(); 2344 } 2345 2346 2347 2348 /** 2349 * Retrieves a prepared string representation of the provided search filter. 2350 * It may potentially be de-anonymized to include specific values. 2351 * 2352 * @param filterString The string representation of the filter to prepare. 2353 * It may be {@code null} if the log message does not 2354 * have a filter. 2355 * 2356 * @return A string representation of the provided filter (which may or may 2357 * not be anonymized), or {@code null} if the provided filter is 2358 * {@code null} or cannot be prepared. 2359 */ 2360 @Nullable() 2361 private String prepareFilter(@Nullable final String filterString) 2362 { 2363 if (filterString == null) 2364 { 2365 return null; 2366 } 2367 2368 if (doNotAnonymize.isPresent()) 2369 { 2370 return filterString.toLowerCase(); 2371 } 2372 2373 try 2374 { 2375 return new GenericFilter(Filter.create(filterString)).toString(). 2376 toLowerCase(); 2377 } 2378 catch (final Exception e) 2379 { 2380 Debug.debugException(e); 2381 return null; 2382 } 2383 } 2384 2385 2386 2387 /** 2388 * Writes a breakdown of the processing times for a specified type of 2389 * operation. 2390 * 2391 * @param t The name of the operation type. 2392 * @param n The total number of operations of the specified type that were 2393 * processed by the server. 2394 * @param m The map of operation counts by processing time bucket. 2395 */ 2396 private void printProcessingTimeHistogram(@NotNull final String t, 2397 final long n, 2398 @NotNull final LinkedHashMap<Long,AtomicLong> m) 2399 { 2400 if (n <= 0) 2401 { 2402 return; 2403 } 2404 2405 out(); 2406 out("Count of ", t, " operations by processing time:"); 2407 2408 long lowerBound = 0; 2409 long accumulatedCount = 0; 2410 final Iterator<Map.Entry<Long,AtomicLong>> i = m.entrySet().iterator(); 2411 while (i.hasNext()) 2412 { 2413 final Map.Entry<Long,AtomicLong> e = i.next(); 2414 final long upperBound = e.getKey(); 2415 final long count = e.getValue().get(); 2416 final double categoryPercent = 100.0 * count / n; 2417 2418 accumulatedCount += count; 2419 final double accumulatedPercent = 100.0 * accumulatedCount / n; 2420 2421 if (i.hasNext()) 2422 { 2423 final String lowerBoundString; 2424 if (lowerBound == 0L) 2425 { 2426 lowerBoundString = "0 milliseconds"; 2427 } 2428 else 2429 { 2430 final long lowerBoundNanos = lowerBound * 1_000_000L; 2431 lowerBoundString = DurationArgument.nanosToDuration(lowerBoundNanos); 2432 } 2433 2434 final long upperBoundNanos = upperBound * 1_000_000L; 2435 final String upperBoundString = 2436 DurationArgument.nanosToDuration(upperBoundNanos); 2437 2438 2439 out("Between ", lowerBoundString, " and ", upperBoundString, ": ", 2440 count, " (", decimalFormat.format(categoryPercent), "%, ", 2441 decimalFormat.format(accumulatedPercent), "% accumulated)"); 2442 lowerBound = upperBound; 2443 } 2444 else 2445 { 2446 final long lowerBoundNanos = lowerBound * 1_000_000L; 2447 final String lowerBoundString = 2448 DurationArgument.nanosToDuration(lowerBoundNanos); 2449 2450 out("Greater than ", lowerBoundString, ": ", count, " (", 2451 decimalFormat.format(categoryPercent), "%, ", 2452 decimalFormat.format(accumulatedPercent), "% accumulated)"); 2453 } 2454 } 2455 } 2456 2457 2458 2459 /** 2460 * Optionally prints information about the number and percent of operations of 2461 * the specified type that involved access to uncached data. 2462 * 2463 * @param operationType The type of operation. 2464 * @param numUncached The number of operations of the specified type that 2465 * involved access to uncached data. 2466 * @param numTotal The total number of operations of the specified 2467 * type. 2468 */ 2469 private void printUncached(@NotNull final String operationType, 2470 final long numUncached, 2471 final long numTotal) 2472 { 2473 if (numUncached == 0) 2474 { 2475 return; 2476 } 2477 2478 out(operationType, ": ", numUncached, " (", 2479 decimalFormat.format(100.0 * numUncached / numTotal), "%)"); 2480 } 2481 2482 2483 2484 /** 2485 * Prints data from the provided map of counts. 2486 * 2487 * @param countMap The map containing the data to print. 2488 * @param heading The heading to display before printing the contents 2489 * of the map. 2490 * @param singularItem The name to use for a single item represented by the 2491 * key of the given map. 2492 * @param pluralItem The name to use for zero or multiple items 2493 * represented by the key of the given map. 2494 */ 2495 private void printCounts(@Nullable final Map<String,AtomicLong> countMap, 2496 @NotNull final String heading, 2497 @NotNull final String singularItem, 2498 @NotNull final String pluralItem) 2499 { 2500 if ((countMap == null) || countMap.isEmpty()) 2501 { 2502 return; 2503 } 2504 2505 long totalCount = 0L; 2506 for (final AtomicLong l : countMap.values()) 2507 { 2508 totalCount += l.get(); 2509 } 2510 2511 out(); 2512 out(heading); 2513 2514 int displayCount = reportCount.getValue(); 2515 if (displayCount <= 0L) 2516 { 2517 displayCount = Integer.MAX_VALUE; 2518 } 2519 2520 final List<ObjectPair<String,Long>> countList = new ArrayList<>(); 2521 final AtomicLong skippedWithSameCount = new AtomicLong(0L); 2522 final AtomicLong skippedWithLowerCount = new AtomicLong(0L); 2523 getMostCommonElements(countMap, countList, displayCount, 2524 skippedWithSameCount, skippedWithLowerCount); 2525 2526 long count = -1L; 2527 for (final ObjectPair<String,Long> p : countList) 2528 { 2529 count = p.getSecond(); 2530 2531 if (totalCount > 0L) 2532 { 2533 final double percent = 100.0 * count / totalCount; 2534 out(p.getFirst(), ": ", count, " (", decimalFormat.format(percent), 2535 ")"); 2536 } 2537 else 2538 { 2539 out(p.getFirst(), ": ", count); 2540 } 2541 } 2542 2543 if (skippedWithSameCount.get() > 0L) 2544 { 2545 out("{ Skipped " + skippedWithSameCount.get() + " additional " + 2546 getSingularOrPlural(skippedWithSameCount.get(), singularItem, 2547 pluralItem) + 2548 " with a count of " + count + " }"); 2549 } 2550 2551 if (skippedWithLowerCount.get() > 0L) 2552 { 2553 out("{ Skipped " + skippedWithLowerCount.get() + " additional " + 2554 getSingularOrPlural(skippedWithLowerCount.get(), singularItem, 2555 pluralItem) + 2556 " with a count that is less than " + count + " }"); 2557 } 2558 } 2559 2560 2561 2562 /** 2563 * Prints data from the provided map of counts. 2564 * 2565 * @param countMap The map containing the data to print. 2566 * @param operationType The type of operation represented by the keys of 2567 * the map. 2568 */ 2569 private void printResultCodeCounts( 2570 @Nullable final Map<ResultCode,AtomicLong> countMap, 2571 @NotNull final String operationType) 2572 { 2573 if ((countMap == null) || countMap.isEmpty()) 2574 { 2575 return; 2576 } 2577 2578 long totalCount = 0L; 2579 for (final AtomicLong l : countMap.values()) 2580 { 2581 totalCount += l.get(); 2582 } 2583 2584 out(); 2585 out("Most common " + operationType + " operation result codes:"); 2586 2587 int displayCount = reportCount.getValue(); 2588 if (displayCount <= 0L) 2589 { 2590 displayCount = Integer.MAX_VALUE; 2591 } 2592 2593 final List<ObjectPair<ResultCode,Long>> resultCodeList = new ArrayList<>(); 2594 final AtomicLong skippedWithSameCount = new AtomicLong(0L); 2595 final AtomicLong skippedWithLowerCount = new AtomicLong(0L); 2596 getMostCommonElements(countMap, resultCodeList, displayCount, 2597 skippedWithSameCount, skippedWithLowerCount); 2598 2599 long count = -1L; 2600 for (final ObjectPair<ResultCode,Long> p : resultCodeList) 2601 { 2602 count = p.getSecond(); 2603 2604 if (totalCount > 0L) 2605 { 2606 final double percent = 100.0 * count / totalCount; 2607 out(p.getFirst().getName(), " (", p.getFirst().intValue(), "): ", 2608 count, " (", decimalFormat.format(percent), ")"); 2609 } 2610 else 2611 { 2612 out(p.getFirst(), ": ", count); 2613 } 2614 } 2615 2616 if (skippedWithSameCount.get() > 0L) 2617 { 2618 out("{ Skipped " + skippedWithSameCount.get() + " additional result " + 2619 getSingularOrPlural(skippedWithSameCount.get(), "code", "codes") + 2620 " with a count of " + count + " }"); 2621 } 2622 2623 if (skippedWithLowerCount.get() > 0L) 2624 { 2625 out("{ Skipped " + skippedWithLowerCount.get() + " additional result " + 2626 getSingularOrPlural(skippedWithLowerCount.get(), "code", "codes") + 2627 " with a count that is less than " + count + " }"); 2628 } 2629 } 2630 2631 2632 2633 /** 2634 * Retrieves the appropriate singular or plural form based on the given 2635 * value. 2636 * 2637 * @param count The count that will be used to determine whether to 2638 * retrieve the singular or plural form. 2639 * @param singular The singular form for the value to return. 2640 * @param plural The plural form for the value to return. 2641 * 2642 * @return The singular form if the count is 1, or the plural form if the 2643 * count is any other value. 2644 */ 2645 @NotNull() 2646 private String getSingularOrPlural(final long count, 2647 @NotNull final String singular, 2648 @NotNull final String plural) 2649 { 2650 if (count == 1L) 2651 { 2652 return singular; 2653 } 2654 else 2655 { 2656 return plural; 2657 } 2658 } 2659}