001/* 002 * The contents of this file are subject to the terms of the Common Development and 003 * Distribution License (the License). You may not use this file except in compliance with the 004 * License. 005 * 006 * You can obtain a copy of the License at legal/CDDLv1.0.txt. See the License for the 007 * specific language governing permission and limitations under the License. 008 * 009 * When distributing Covered Software, include this CDDL Header Notice in each file and include 010 * the License file at legal/CDDLv1.0.txt. If applicable, add the following below the CDDL 011 * Header, with the fields enclosed by brackets [] replaced by your own identifying 012 * information: "Portions Copyright [year] [name of copyright owner]". 013 * 014 * Copyright 2006-2009 Sun Microsystems, Inc. 015 * Portions Copyright 2011-2016 ForgeRock AS. 016 */ 017package org.opends.server.loggers; 018 019import static org.opends.messages.LoggerMessages.ERR_COMMON_AUDIT_INVALID_TRANSACTION_ID; 020import static org.opends.messages.ConfigMessages.*; 021import static org.opends.server.util.StaticUtils.*; 022 023import java.io.File; 024import java.io.IOException; 025import java.text.SimpleDateFormat; 026import java.util.List; 027import java.util.Set; 028 029import org.forgerock.i18n.LocalizableMessage; 030import org.forgerock.i18n.LocalizableMessageBuilder; 031import org.forgerock.opendj.config.server.ConfigChangeResult; 032import org.forgerock.opendj.config.server.ConfigException; 033import org.forgerock.opendj.ldap.ByteString; 034import org.forgerock.opendj.ldap.DN; 035import org.forgerock.opendj.ldap.ResultCode; 036import org.forgerock.util.Utils; 037import org.forgerock.opendj.config.server.ConfigurationChangeListener; 038import org.forgerock.opendj.server.config.meta.FileBasedAccessLogPublisherCfgDefn.LogFormat; 039import org.forgerock.opendj.server.config.server.FileBasedAccessLogPublisherCfg; 040import org.opends.server.api.ClientConnection; 041import org.opends.server.api.ExtendedOperationHandler; 042import org.opends.server.controls.TransactionIdControl; 043import org.opends.server.core.AbandonOperation; 044import org.opends.server.core.AddOperation; 045import org.opends.server.core.BindOperation; 046import org.opends.server.core.CompareOperation; 047import org.opends.server.core.DeleteOperation; 048import org.opends.server.core.DirectoryServer; 049import org.opends.server.core.ExtendedOperation; 050import org.opends.server.core.ModifyDNOperation; 051import org.opends.server.core.ModifyOperation; 052import org.opends.server.core.SearchOperation; 053import org.opends.server.core.ServerContext; 054import org.opends.server.core.UnbindOperation; 055import org.opends.server.types.AdditionalLogItem; 056import org.opends.server.types.AuthenticationInfo; 057import org.opends.server.types.Control; 058import org.opends.server.types.DirectoryException; 059import org.opends.server.types.DisconnectReason; 060import org.opends.server.types.FilePermission; 061import org.opends.server.types.InitializationException; 062import org.opends.server.types.Operation; 063import org.opends.server.util.StaticUtils; 064import org.opends.server.util.TimeThread; 065 066/** This class provides the implementation of the access logger used by the directory server. */ 067public final class TextAccessLogPublisher extends 068 AbstractTextAccessLogPublisher<FileBasedAccessLogPublisherCfg> implements 069 ConfigurationChangeListener<FileBasedAccessLogPublisherCfg> 070{ 071 /** The category to use when logging responses. */ 072 private static final String CATEGORY_RESPONSE = "RES"; 073 /** The category to use when logging requests. */ 074 private static final String CATEGORY_REQUEST = "REQ"; 075 076 /** 077 * Returns an instance of the text access log publisher that will print all 078 * messages to the provided writer. This is used to print the messages to the 079 * console when the server starts up. 080 * 081 * @param writer 082 * The text writer where the message will be written to. 083 * @param suppressInternal 084 * Indicates whether to suppress internal operations. 085 * @return The instance of the text error log publisher that will print all 086 * messages to standard out. 087 */ 088 public static TextAccessLogPublisher getStartupTextAccessPublisher( 089 final TextWriter writer, final boolean suppressInternal) 090 { 091 final TextAccessLogPublisher startupPublisher = new TextAccessLogPublisher(); 092 startupPublisher.writer = writer; 093 startupPublisher.buildFilters(suppressInternal); 094 return startupPublisher; 095 } 096 097 private TextWriter writer; 098 private FileBasedAccessLogPublisherCfg cfg; 099 private boolean isCombinedMode; 100 private boolean includeControlOIDs; 101 private String timeStampFormat = "dd/MMM/yyyy:HH:mm:ss Z"; 102 private ServerContext serverContext; 103 104 @Override 105 public ConfigChangeResult applyConfigurationChange(FileBasedAccessLogPublisherCfg config) 106 { 107 final ConfigChangeResult ccr = new ConfigChangeResult(); 108 109 try 110 { 111 // Determine the writer we are using. If we were writing asynchronously, 112 // we need to modify the underlying writer. 113 TextWriter currentWriter; 114 if (writer instanceof AsynchronousTextWriter) 115 { 116 currentWriter = ((AsynchronousTextWriter) writer).getWrappedWriter(); 117 } 118 else 119 { 120 currentWriter = writer; 121 } 122 123 if (currentWriter instanceof MultifileTextWriter) 124 { 125 final MultifileTextWriter mfWriter = (MultifileTextWriter) currentWriter; 126 configure(mfWriter, config); 127 128 if (config.isAsynchronous()) 129 { 130 if (writer instanceof AsynchronousTextWriter) 131 { 132 if (hasAsyncConfigChanged(config)) 133 { 134 // reinstantiate 135 final AsynchronousTextWriter previousWriter = (AsynchronousTextWriter) writer; 136 writer = newAsyncWriter(mfWriter, config); 137 previousWriter.shutdown(false); 138 } 139 } 140 else 141 { 142 // turn async text writer on 143 writer = newAsyncWriter(mfWriter, config); 144 } 145 } 146 else 147 { 148 if (writer instanceof AsynchronousTextWriter) 149 { 150 // asynchronous is being turned off, remove async text writers. 151 final AsynchronousTextWriter previousWriter = (AsynchronousTextWriter) writer; 152 writer = mfWriter; 153 previousWriter.shutdown(false); 154 } 155 } 156 157 if (cfg.isAsynchronous() && config.isAsynchronous() 158 && cfg.getQueueSize() != config.getQueueSize()) 159 { 160 ccr.setAdminActionRequired(true); 161 } 162 163 if (!config.getLogRecordTimeFormat().equals(timeStampFormat)) 164 { 165 TimeThread.removeUserDefinedFormatter(timeStampFormat); 166 timeStampFormat = config.getLogRecordTimeFormat(); 167 } 168 169 cfg = config; 170 isCombinedMode = cfg.getLogFormat() == LogFormat.COMBINED; 171 includeControlOIDs = cfg.isLogControlOids(); 172 } 173 } 174 catch (final Exception e) 175 { 176 ccr.setResultCode(DirectoryServer.getServerErrorResultCode()); 177 ccr.addMessage(ERR_CONFIG_LOGGING_CANNOT_CREATE_WRITER.get( 178 config.dn(), stackTraceToSingleLineString(e))); 179 } 180 181 return ccr; 182 } 183 184 private void configure(MultifileTextWriter mfWriter, FileBasedAccessLogPublisherCfg config) throws DirectoryException 185 { 186 final FilePermission perm = FilePermission.decodeUNIXMode(config.getLogFilePermissions()); 187 final boolean writerAutoFlush = config.isAutoFlush() && !config.isAsynchronous(); 188 189 final File logFile = getLogFile(config); 190 final FileNamingPolicy fnPolicy = new TimeStampNaming(logFile); 191 192 mfWriter.setNamingPolicy(fnPolicy); 193 mfWriter.setFilePermissions(perm); 194 mfWriter.setAppend(config.isAppend()); 195 mfWriter.setAutoFlush(writerAutoFlush); 196 mfWriter.setBufferSize((int) config.getBufferSize()); 197 mfWriter.setInterval(config.getTimeInterval()); 198 199 mfWriter.removeAllRetentionPolicies(); 200 mfWriter.removeAllRotationPolicies(); 201 for (final DN dn : config.getRotationPolicyDNs()) 202 { 203 mfWriter.addRotationPolicy(DirectoryServer.getRotationPolicy(dn)); 204 } 205 for (final DN dn : config.getRetentionPolicyDNs()) 206 { 207 mfWriter.addRetentionPolicy(DirectoryServer.getRetentionPolicy(dn)); 208 } 209 } 210 211 private File getLogFile(final FileBasedAccessLogPublisherCfg config) 212 { 213 return getFileForPath(config.getLogFile()); 214 } 215 216 @Override 217 public void initializeLogPublisher(final FileBasedAccessLogPublisherCfg cfg, ServerContext serverContext) 218 throws ConfigException, InitializationException 219 { 220 this.serverContext = serverContext; 221 final File logFile = getLogFile(cfg); 222 final FileNamingPolicy fnPolicy = new TimeStampNaming(logFile); 223 224 try 225 { 226 final FilePermission perm = FilePermission.decodeUNIXMode(cfg.getLogFilePermissions()); 227 final LogPublisherErrorHandler errorHandler = new LogPublisherErrorHandler(cfg.dn()); 228 final boolean writerAutoFlush = cfg.isAutoFlush() && !cfg.isAsynchronous(); 229 230 final MultifileTextWriter theWriter = new MultifileTextWriter( 231 "Multifile Text Writer for " + cfg.dn(), 232 cfg.getTimeInterval(), fnPolicy, perm, errorHandler, "UTF-8", 233 writerAutoFlush, cfg.isAppend(), (int) cfg.getBufferSize()); 234 235 // Validate retention and rotation policies. 236 for (final DN dn : cfg.getRotationPolicyDNs()) 237 { 238 theWriter.addRotationPolicy(DirectoryServer.getRotationPolicy(dn)); 239 } 240 for (final DN dn : cfg.getRetentionPolicyDNs()) 241 { 242 theWriter.addRetentionPolicy(DirectoryServer.getRetentionPolicy(dn)); 243 } 244 245 if (cfg.isAsynchronous()) 246 { 247 this.writer = newAsyncWriter(theWriter, cfg); 248 } 249 else 250 { 251 this.writer = theWriter; 252 } 253 } 254 catch (final DirectoryException e) 255 { 256 throw new InitializationException( 257 ERR_CONFIG_LOGGING_CANNOT_CREATE_WRITER.get(cfg.dn(), e), e); 258 } 259 catch (final IOException e) 260 { 261 throw new InitializationException( 262 ERR_CONFIG_LOGGING_CANNOT_OPEN_FILE.get(logFile, cfg.dn(), e), e); 263 } 264 265 initializeFilters(cfg); 266 267 this.cfg = cfg; 268 isCombinedMode = cfg.getLogFormat() == LogFormat.COMBINED; 269 includeControlOIDs = cfg.isLogControlOids(); 270 timeStampFormat = cfg.getLogRecordTimeFormat(); 271 272 cfg.addFileBasedAccessChangeListener(this); 273 } 274 275 private boolean hasAsyncConfigChanged(FileBasedAccessLogPublisherCfg newConfig) 276 { 277 return hasParallelConfigChanged(newConfig) && cfg.getQueueSize() != newConfig.getQueueSize(); 278 } 279 280 private boolean hasParallelConfigChanged(FileBasedAccessLogPublisherCfg newConfig) 281 { 282 return !cfg.dn().equals(newConfig.dn()) && cfg.isAutoFlush() != newConfig.isAutoFlush(); 283 } 284 285 private AsynchronousTextWriter newAsyncWriter(MultifileTextWriter mfWriter, FileBasedAccessLogPublisherCfg config) 286 { 287 String name = "Asynchronous Text Writer for " + config.dn(); 288 return new AsynchronousTextWriter(name, config.getQueueSize(), config.isAutoFlush(), mfWriter); 289 } 290 291 @Override 292 public boolean isConfigurationAcceptable( 293 final FileBasedAccessLogPublisherCfg configuration, 294 final List<LocalizableMessage> unacceptableReasons) 295 { 296 return isFilterConfigurationAcceptable(configuration, unacceptableReasons) 297 && isConfigurationChangeAcceptable(configuration, unacceptableReasons); 298 } 299 300 @Override 301 public boolean isConfigurationChangeAcceptable( 302 final FileBasedAccessLogPublisherCfg config, 303 final List<LocalizableMessage> unacceptableReasons) 304 { 305 // Validate the time-stamp formatter. 306 final String formatString = config.getLogRecordTimeFormat(); 307 try 308 { 309 new SimpleDateFormat(formatString); 310 } 311 catch (final Exception e) 312 { 313 final LocalizableMessage message = ERR_CONFIG_LOGGING_INVALID_TIME_FORMAT.get(formatString); 314 unacceptableReasons.add(message); 315 return false; 316 } 317 318 // Make sure the permission is valid. 319 try 320 { 321 final FilePermission filePerm = FilePermission.decodeUNIXMode(config.getLogFilePermissions()); 322 if (!filePerm.isOwnerWritable()) 323 { 324 final LocalizableMessage message = ERR_CONFIG_LOGGING_INSANE_MODE.get(config.getLogFilePermissions()); 325 unacceptableReasons.add(message); 326 return false; 327 } 328 } 329 catch (final DirectoryException e) 330 { 331 unacceptableReasons.add(ERR_CONFIG_LOGGING_MODE_INVALID.get(config.getLogFilePermissions(), e)); 332 return false; 333 } 334 335 return true; 336 } 337 338 @Override 339 public void logAbandonRequest(final AbandonOperation abandonOperation) 340 { 341 if (isCombinedMode || !isRequestLoggable(abandonOperation)) 342 { 343 return; 344 } 345 346 final StringBuilder buffer = new StringBuilder(100); 347 appendHeader(abandonOperation, "ABANDON", CATEGORY_REQUEST, buffer); 348 appendAbandonRequest(abandonOperation, buffer); 349 writer.writeRecord(buffer.toString()); 350 } 351 352 @Override 353 public void logAbandonResult(final AbandonOperation abandonOperation) 354 { 355 if (!isResponseLoggable(abandonOperation)) 356 { 357 return; 358 } 359 360 final StringBuilder buffer = new StringBuilder(100); 361 appendHeader(abandonOperation, "ABANDON", CATEGORY_RESPONSE, buffer); 362 if (isCombinedMode) 363 { 364 appendAbandonRequest(abandonOperation, buffer); 365 } 366 appendResultCodeAndMessage(buffer, abandonOperation); 367 logAdditionalLogItems(abandonOperation, buffer); 368 appendEtime(buffer, abandonOperation); 369 writer.writeRecord(buffer.toString()); 370 } 371 372 @Override 373 public void logAddRequest(final AddOperation addOperation) 374 { 375 if (isCombinedMode || !isRequestLoggable(addOperation)) 376 { 377 return; 378 } 379 380 final StringBuilder buffer = new StringBuilder(100); 381 appendHeader(addOperation, "ADD", CATEGORY_REQUEST, buffer); 382 appendAddRequest(addOperation, buffer); 383 writer.writeRecord(buffer.toString()); 384 } 385 386 @Override 387 public void logAddResponse(final AddOperation addOperation) 388 { 389 if (!isResponseLoggable(addOperation)) 390 { 391 return; 392 } 393 394 final StringBuilder buffer = new StringBuilder(100); 395 appendHeader(addOperation, "ADD", CATEGORY_RESPONSE, buffer); 396 if (isCombinedMode) 397 { 398 appendAddRequest(addOperation, buffer); 399 } 400 appendResultCodeAndMessage(buffer, addOperation); 401 logAdditionalLogItems(addOperation, buffer); 402 appendLabelIfNotNull(buffer, "authzDN", addOperation.getProxiedAuthorizationDN()); 403 appendEtime(buffer, addOperation); 404 writer.writeRecord(buffer.toString()); 405 } 406 407 @Override 408 public void logBindRequest(final BindOperation bindOperation) 409 { 410 if (isCombinedMode || !isRequestLoggable(bindOperation)) 411 { 412 return; 413 } 414 415 final StringBuilder buffer = new StringBuilder(100); 416 appendHeader(bindOperation, "BIND", CATEGORY_REQUEST, buffer); 417 appendBindRequest(bindOperation, buffer); 418 writer.writeRecord(buffer.toString()); 419 } 420 421 @Override 422 public void logBindResponse(final BindOperation bindOperation) 423 { 424 if (!isResponseLoggable(bindOperation)) 425 { 426 return; 427 } 428 429 final StringBuilder buffer = new StringBuilder(100); 430 appendHeader(bindOperation, "BIND", CATEGORY_RESPONSE, buffer); 431 if (isCombinedMode) 432 { 433 appendBindRequest(bindOperation, buffer); 434 } 435 appendResultCodeAndMessage(buffer, bindOperation); 436 437 final LocalizableMessage failureMessage = bindOperation.getAuthFailureReason(); 438 if (failureMessage != null) 439 { 440 // this code path is mutually exclusive with the if result code is success down below 441 appendLabel(buffer, "authFailureReason", failureMessage); 442 if (bindOperation.getSASLMechanism() != null 443 && bindOperation.getSASLAuthUserEntry() != null) 444 { // SASL bind and we have successfully found a user entry for auth 445 appendLabel(buffer, "authDN", bindOperation.getSASLAuthUserEntry().getName()); 446 } 447 else 448 { // SASL bind failed to find user entry for auth or simple bind 449 appendLabel(buffer, "authDN", bindOperation.getRawBindDN()); 450 } 451 } 452 453 logAdditionalLogItems(bindOperation, buffer); 454 455 if (bindOperation.getResultCode() == ResultCode.SUCCESS) 456 { 457 // this code path is mutually exclusive with the if failure message that exists just above 458 final AuthenticationInfo authInfo = bindOperation.getAuthenticationInfo(); 459 if (authInfo != null) 460 { 461 final DN authDN = authInfo.getAuthenticationDN(); 462 if (authDN != null) 463 { 464 appendLabel(buffer, "authDN", authDN); 465 466 final DN authzDN = authInfo.getAuthorizationDN(); 467 if (!authDN.equals(authzDN)) 468 { 469 appendLabel(buffer, "authzDN", authzDN); 470 } 471 } 472 else 473 { 474 buffer.append(" authDN=\"\""); 475 } 476 } 477 } 478 479 appendEtime(buffer, bindOperation); 480 481 writer.writeRecord(buffer.toString()); 482 } 483 484 @Override 485 public void logCompareRequest(final CompareOperation compareOperation) 486 { 487 if (isCombinedMode || !isRequestLoggable(compareOperation)) 488 { 489 return; 490 } 491 492 final StringBuilder buffer = new StringBuilder(100); 493 appendHeader(compareOperation, "COMPARE", CATEGORY_REQUEST, buffer); 494 appendCompareRequest(compareOperation, buffer); 495 writer.writeRecord(buffer.toString()); 496 } 497 498 @Override 499 public void logCompareResponse(final CompareOperation compareOperation) 500 { 501 if (!isResponseLoggable(compareOperation)) 502 { 503 return; 504 } 505 506 final StringBuilder buffer = new StringBuilder(100); 507 appendHeader(compareOperation, "COMPARE", CATEGORY_RESPONSE, buffer); 508 if (isCombinedMode) 509 { 510 appendCompareRequest(compareOperation, buffer); 511 } 512 appendResultCodeAndMessage(buffer, compareOperation); 513 logAdditionalLogItems(compareOperation, buffer); 514 appendLabelIfNotNull(buffer, "authzDN", compareOperation.getProxiedAuthorizationDN()); 515 appendEtime(buffer, compareOperation); 516 writer.writeRecord(buffer.toString()); 517 } 518 519 @Override 520 public void logConnect(final ClientConnection clientConnection) 521 { 522 if (!isConnectLoggable(clientConnection)) 523 { 524 return; 525 } 526 527 final long connectionID = clientConnection.getConnectionID(); 528 final StringBuilder buffer = new StringBuilder(100); 529 buffer.append('[').append(TimeThread.getUserDefinedTime(timeStampFormat)).append(']'); 530 buffer.append(" CONNECT conn=").append(connectionID); 531 buffer.append(" from=").append(clientConnection.getClientHostPort()); 532 buffer.append(" to=").append(clientConnection.getServerHostPort()); 533 buffer.append(" protocol=").append(clientConnection.getProtocol()); 534 535 writer.writeRecord(buffer.toString()); 536 } 537 538 @Override 539 public void logDeleteRequest(final DeleteOperation deleteOperation) 540 { 541 if (isCombinedMode || !isRequestLoggable(deleteOperation)) 542 { 543 return; 544 } 545 546 final StringBuilder buffer = new StringBuilder(100); 547 appendHeader(deleteOperation, "DELETE", CATEGORY_REQUEST, buffer); 548 appendDeleteRequest(deleteOperation, buffer); 549 writer.writeRecord(buffer.toString()); 550 } 551 552 @Override 553 public void logDeleteResponse(final DeleteOperation deleteOperation) 554 { 555 if (!isResponseLoggable(deleteOperation)) 556 { 557 return; 558 } 559 560 final StringBuilder buffer = new StringBuilder(100); 561 appendHeader(deleteOperation, "DELETE", CATEGORY_RESPONSE, buffer); 562 if (isCombinedMode) 563 { 564 appendDeleteRequest(deleteOperation, buffer); 565 } 566 appendResultCodeAndMessage(buffer, deleteOperation); 567 logAdditionalLogItems(deleteOperation, buffer); 568 appendLabelIfNotNull(buffer, "authzDN", deleteOperation.getProxiedAuthorizationDN()); 569 appendEtime(buffer, deleteOperation); 570 writer.writeRecord(buffer.toString()); 571 } 572 573 @Override 574 public void logDisconnect(final ClientConnection clientConnection, 575 final DisconnectReason disconnectReason, final LocalizableMessage message) 576 { 577 if (!isDisconnectLoggable(clientConnection)) 578 { 579 return; 580 } 581 582 final long connectionID = clientConnection.getConnectionID(); 583 final StringBuilder buffer = new StringBuilder(100); 584 buffer.append('[').append(TimeThread.getUserDefinedTime(timeStampFormat)).append(']'); 585 buffer.append(" DISCONNECT conn=").append(connectionID); 586 appendLabel(buffer, "reason", disconnectReason); 587 appendLabelIfNotNull(buffer, "msg", message); 588 589 writer.writeRecord(buffer.toString()); 590 } 591 592 @Override 593 public void logExtendedRequest(final ExtendedOperation extendedOperation) 594 { 595 if (isCombinedMode || !isRequestLoggable(extendedOperation)) 596 { 597 return; 598 } 599 600 final StringBuilder buffer = new StringBuilder(100); 601 appendHeader(extendedOperation, "EXTENDED", CATEGORY_REQUEST, buffer); 602 appendExtendedRequest(extendedOperation, buffer); 603 writer.writeRecord(buffer.toString()); 604 } 605 606 @Override 607 public void logExtendedResponse(final ExtendedOperation extendedOperation) 608 { 609 if (!isResponseLoggable(extendedOperation)) 610 { 611 return; 612 } 613 614 final StringBuilder buffer = new StringBuilder(100); 615 appendHeader(extendedOperation, "EXTENDED", CATEGORY_RESPONSE, buffer); 616 if (isCombinedMode) 617 { 618 appendExtendedRequest(extendedOperation, buffer); 619 } 620 621 final String oid = extendedOperation.getResponseOID(); 622 if (oid != null) 623 { 624 final ExtendedOperationHandler<?> extOpHandler = DirectoryServer 625 .getExtendedOperationHandler(oid); 626 if (extOpHandler != null) 627 { 628 String name = extOpHandler.getExtendedOperationName(); 629 appendLabelIfNotNull(buffer, "name", name); 630 } 631 appendLabel(buffer, "oid", oid); 632 } 633 appendResultCodeAndMessage(buffer, extendedOperation); 634 logAdditionalLogItems(extendedOperation, buffer); 635 appendEtime(buffer, extendedOperation); 636 637 writer.writeRecord(buffer.toString()); 638 } 639 640 @Override 641 public void logModifyDNRequest(final ModifyDNOperation modifyDNOperation) 642 { 643 if (isCombinedMode || !isRequestLoggable(modifyDNOperation)) 644 { 645 return; 646 } 647 648 final StringBuilder buffer = new StringBuilder(100); 649 appendHeader(modifyDNOperation, "MODIFYDN", CATEGORY_REQUEST, buffer); 650 appendModifyDNRequest(modifyDNOperation, buffer); 651 writer.writeRecord(buffer.toString()); 652 } 653 654 @Override 655 public void logModifyDNResponse(final ModifyDNOperation modifyDNOperation) 656 { 657 if (!isResponseLoggable(modifyDNOperation)) 658 { 659 return; 660 } 661 662 final StringBuilder buffer = new StringBuilder(100); 663 appendHeader(modifyDNOperation, "MODIFYDN", CATEGORY_RESPONSE, buffer); 664 if (isCombinedMode) 665 { 666 appendModifyDNRequest(modifyDNOperation, buffer); 667 } 668 appendResultCodeAndMessage(buffer, modifyDNOperation); 669 logAdditionalLogItems(modifyDNOperation, buffer); 670 appendLabelIfNotNull(buffer, "authzDN", modifyDNOperation.getProxiedAuthorizationDN()); 671 appendEtime(buffer, modifyDNOperation); 672 writer.writeRecord(buffer.toString()); 673 } 674 675 @Override 676 public void logModifyRequest(final ModifyOperation modifyOperation) 677 { 678 if (isCombinedMode || !isRequestLoggable(modifyOperation)) 679 { 680 return; 681 } 682 683 final StringBuilder buffer = new StringBuilder(100); 684 appendHeader(modifyOperation, "MODIFY", CATEGORY_REQUEST, buffer); 685 appendModifyRequest(modifyOperation, buffer); 686 writer.writeRecord(buffer.toString()); 687 } 688 689 @Override 690 public void logModifyResponse(final ModifyOperation modifyOperation) 691 { 692 if (!isResponseLoggable(modifyOperation)) 693 { 694 return; 695 } 696 697 final StringBuilder buffer = new StringBuilder(100); 698 appendHeader(modifyOperation, "MODIFY", CATEGORY_RESPONSE, buffer); 699 if (isCombinedMode) 700 { 701 appendModifyRequest(modifyOperation, buffer); 702 } 703 appendResultCodeAndMessage(buffer, modifyOperation); 704 logAdditionalLogItems(modifyOperation, buffer); 705 appendLabelIfNotNull(buffer, "authzDN", modifyOperation.getProxiedAuthorizationDN()); 706 appendEtime(buffer, modifyOperation); 707 writer.writeRecord(buffer.toString()); 708 } 709 710 @Override 711 public void logSearchRequest(final SearchOperation searchOperation) 712 { 713 if (isCombinedMode || !isRequestLoggable(searchOperation)) 714 { 715 return; 716 } 717 718 final StringBuilder buffer = new StringBuilder(192); 719 appendHeader(searchOperation, "SEARCH", CATEGORY_REQUEST, buffer); 720 appendSearchRequest(searchOperation, buffer); 721 writer.writeRecord(buffer.toString()); 722 } 723 724 @Override 725 public void logSearchResultDone(final SearchOperation searchOperation) 726 { 727 if (!isResponseLoggable(searchOperation)) 728 { 729 return; 730 } 731 732 final StringBuilder buffer = new StringBuilder(128); 733 appendHeader(searchOperation, "SEARCH", CATEGORY_RESPONSE, buffer); 734 if (isCombinedMode) 735 { 736 appendSearchRequest(searchOperation, buffer); 737 } 738 appendResultCodeAndMessage(buffer, searchOperation); 739 buffer.append(" nentries=").append(searchOperation.getEntriesSent()); 740 logAdditionalLogItems(searchOperation, buffer); 741 appendLabelIfNotNull(buffer, "authzDN", searchOperation.getProxiedAuthorizationDN()); 742 appendEtime(buffer, searchOperation); 743 writer.writeRecord(buffer.toString()); 744 } 745 746 @Override 747 public void logUnbind(final UnbindOperation unbindOperation) 748 { 749 if (!isRequestLoggable(unbindOperation)) 750 { 751 return; 752 } 753 754 final StringBuilder buffer = new StringBuilder(100); 755 appendHeader(unbindOperation, "UNBIND", CATEGORY_REQUEST, buffer); 756 if (unbindOperation.isSynchronizationOperation()) 757 { 758 buffer.append(" type=synchronization"); 759 } 760 761 writer.writeRecord(buffer.toString()); 762 } 763 764 @Override 765 protected void close0() 766 { 767 writer.shutdown(); 768 TimeThread.removeUserDefinedFormatter(timeStampFormat); 769 if (cfg != null) 770 { 771 cfg.removeFileBasedAccessChangeListener(this); 772 } 773 } 774 775 private void appendAbandonRequest(final AbandonOperation abandonOperation, final StringBuilder buffer) 776 { 777 buffer.append(" idToAbandon="); 778 buffer.append(abandonOperation.getIDToAbandon()); 779 appendRequestControls(abandonOperation, buffer); 780 if (abandonOperation.isSynchronizationOperation()) 781 { 782 buffer.append(" type=synchronization"); 783 } 784 } 785 786 private void appendAddRequest(final AddOperation addOperation, final StringBuilder buffer) 787 { 788 appendLabel(buffer, "dn", addOperation.getRawEntryDN()); 789 appendRequestControls(addOperation, buffer); 790 if (addOperation.isSynchronizationOperation()) 791 { 792 buffer.append(" type=synchronization"); 793 } 794 } 795 796 private void appendBindRequest(final BindOperation bindOperation, final StringBuilder buffer) 797 { 798 final String protocolVersion = bindOperation.getProtocolVersion(); 799 if (protocolVersion != null) 800 { 801 buffer.append(" version="); 802 buffer.append(protocolVersion); 803 } 804 805 switch (bindOperation.getAuthenticationType()) 806 { 807 case SIMPLE: 808 buffer.append(" type=SIMPLE"); 809 break; 810 case SASL: 811 buffer.append(" type=SASL mechanism=").append(bindOperation.getSASLMechanism()); 812 break; 813 default: 814 buffer.append(" type=").append(bindOperation.getAuthenticationType()); 815 break; 816 } 817 818 appendLabel(buffer, "dn", bindOperation.getRawBindDN()); 819 appendRequestControls(bindOperation, buffer); 820 if (bindOperation.isSynchronizationOperation()) 821 { 822 buffer.append(" type=synchronization"); 823 } 824 } 825 826 private void appendCompareRequest(final CompareOperation compareOperation, final StringBuilder buffer) 827 { 828 appendLabel(buffer, "dn", compareOperation.getRawEntryDN()); 829 buffer.append(" attr="); 830 buffer.append(compareOperation.getAttributeDescription().getAttributeType().getNameOrOID()); 831 appendRequestControls(compareOperation, buffer); 832 if (compareOperation.isSynchronizationOperation()) 833 { 834 buffer.append(" type=synchronization"); 835 } 836 } 837 838 private void appendDeleteRequest(final DeleteOperation deleteOperation, final StringBuilder buffer) 839 { 840 appendLabel(buffer, "dn", deleteOperation.getRawEntryDN()); 841 appendRequestControls(deleteOperation, buffer); 842 if (deleteOperation.isSynchronizationOperation()) 843 { 844 buffer.append(" type=synchronization"); 845 } 846 } 847 848 private void appendExtendedRequest(final ExtendedOperation extendedOperation, 849 final StringBuilder buffer) 850 { 851 final String oid = extendedOperation.getRequestOID(); 852 final ExtendedOperationHandler<?> extOpHandler = DirectoryServer.getExtendedOperationHandler(oid); 853 if (extOpHandler != null) 854 { 855 final String name = extOpHandler.getExtendedOperationName(); 856 appendLabelIfNotNull(buffer, "name", name); 857 } 858 appendLabel(buffer, "oid", oid); 859 appendRequestControls(extendedOperation, buffer); 860 if (extendedOperation.isSynchronizationOperation()) 861 { 862 buffer.append(" type=synchronization"); 863 } 864 } 865 866 private void appendLabel(final StringBuilder buffer, final String label, final Object obj) 867 { 868 buffer.append(' ').append(label).append("=\""); 869 if (obj != null) 870 { 871 buffer.append(obj); 872 } 873 buffer.append('\"'); 874 } 875 876 private void appendLabelIfNotNull(final StringBuilder buffer, final String label, final Object obj) 877 { 878 if (obj != null) 879 { 880 appendLabel(buffer, label, obj); 881 } 882 } 883 884 private void appendResultCodeAndMessage(StringBuilder buffer, Operation operation) 885 { 886 buffer.append(" result="); 887 buffer.append(operation.getResultCode().intValue()); 888 889 final LocalizableMessageBuilder msg = operation.getErrorMessage(); 890 if (msg != null && msg.length() > 0) 891 { 892 appendLabel(buffer, "message", msg); 893 } 894 895 if (operation.getMaskedResultCode() != null) 896 { 897 buffer.append(" maskedResult="); 898 buffer.append(operation.getMaskedResultCode().intValue()); 899 } 900 final LocalizableMessageBuilder maskedMsg = operation.getMaskedErrorMessage(); 901 if (maskedMsg != null && maskedMsg.length() > 0) 902 { 903 appendLabel(buffer, "maskedMessage", maskedMsg); 904 } 905 } 906 907 private void appendEtime(final StringBuilder buffer, final Operation operation) 908 { 909 buffer.append(" etime="); 910 // the server can be configured to log processing time as nanos xor millis 911 long etime = operation.getProcessingNanoTime(); 912 if (etime <= -1) 913 { 914 // if it is not configured for nanos, then use millis. 915 etime = operation.getProcessingTime(); 916 } 917 buffer.append(etime); 918 } 919 920 /** Appends the common log header information to the provided buffer. */ 921 private void appendHeader(final Operation operation, final String opType, 922 final String category, final StringBuilder buffer) 923 { 924 buffer.append('[').append(TimeThread.getUserDefinedTime(timeStampFormat)).append("] "); 925 buffer.append(opType); 926 if (!isCombinedMode) 927 { 928 buffer.append(' ').append(category); 929 } 930 buffer.append(" conn=").append(operation.getConnectionID()); 931 buffer.append(" op=").append(operation.getOperationID()); 932 buffer.append(" msgID=").append(operation.getMessageID()); 933 appendTransactionId(operation, buffer); 934 } 935 936 private void appendModifyDNRequest(final ModifyDNOperation modifyDNOperation, 937 final StringBuilder buffer) 938 { 939 appendLabel(buffer, "dn", modifyDNOperation.getRawEntryDN()); 940 appendLabel(buffer, "newRDN", modifyDNOperation.getRawNewRDN()); 941 appendLabel(buffer, "deleteOldRDN", modifyDNOperation.deleteOldRDN()); 942 943 final ByteString newSuperior = modifyDNOperation.getRawNewSuperior(); 944 appendLabelIfNotNull(buffer, "newSuperior", newSuperior); 945 appendRequestControls(modifyDNOperation, buffer); 946 if (modifyDNOperation.isSynchronizationOperation()) 947 { 948 buffer.append(" type=synchronization"); 949 } 950 } 951 952 private void appendModifyRequest(final ModifyOperation modifyOperation, final StringBuilder buffer) 953 { 954 appendLabel(buffer, "dn", modifyOperation.getRawEntryDN()); 955 appendRequestControls(modifyOperation, buffer); 956 if (modifyOperation.isSynchronizationOperation()) 957 { 958 buffer.append(" type=synchronization"); 959 } 960 } 961 962 private void appendTransactionId(Operation operation, final StringBuilder buffer) 963 { 964 // In test context, serverContext may be null 965 if (serverContext != null && serverContext.getCommonAudit().shouldTrustTransactionIds()) 966 { 967 String transactionId = getTransactionIdFromControl(operation); 968 if (transactionId != null) 969 { 970 buffer.append(" transactionId=").append(transactionId); 971 } 972 } 973 } 974 975 private String getTransactionIdFromControl(Operation operation) 976 { 977 try 978 { 979 TransactionIdControl control = operation.getRequestControl(TransactionIdControl.DECODER); 980 return control != null ? control.getTransactionId() : null; 981 } 982 catch (DirectoryException e) 983 { 984 logger.error(ERR_COMMON_AUDIT_INVALID_TRANSACTION_ID.get(StaticUtils.stackTraceToSingleLineString(e))); 985 } 986 return null; 987 } 988 989 private void appendRequestControls(final Operation operation, final StringBuilder buffer) 990 { 991 appendControls(buffer, " requestControls=", operation.getRequestControls()); 992 } 993 994 private void appendResponseControls(final Operation operation, final StringBuilder buffer) 995 { 996 appendControls(buffer, " responseControls=", operation.getResponseControls()); 997 } 998 999 private void appendControls(final StringBuilder buffer, String label, List<Control> controls) 1000 { 1001 if (includeControlOIDs && !controls.isEmpty()) 1002 { 1003 buffer.append(label); 1004 boolean isFirst = true; 1005 for (final Control control : controls) 1006 { 1007 if (!isFirst) 1008 { 1009 buffer.append(","); 1010 } 1011 buffer.append(control.getOID()); 1012 isFirst = false; 1013 } 1014 } 1015 } 1016 1017 private void appendSearchRequest(final SearchOperation searchOperation, final StringBuilder buffer) 1018 { 1019 appendLabel(buffer, "base", searchOperation.getRawBaseDN()); 1020 buffer.append(" scope="); 1021 buffer.append(searchOperation.getScope()); 1022 buffer.append(" filter=\""); 1023 searchOperation.getRawFilter().toString(buffer); 1024 1025 final Set<String> attrs = searchOperation.getAttributes(); 1026 if (attrs == null || attrs.isEmpty()) 1027 { 1028 buffer.append("\" attrs=\"ALL\""); 1029 } 1030 else 1031 { 1032 buffer.append("\" attrs=\""); 1033 Utils.joinAsString(buffer, ",", attrs); 1034 buffer.append("\""); 1035 } 1036 appendRequestControls(searchOperation, buffer); 1037 if (searchOperation.isSynchronizationOperation()) 1038 { 1039 buffer.append(" type=synchronization"); 1040 } 1041 } 1042 1043 /** Appends additional log items to the provided builder. */ 1044 private void logAdditionalLogItems(final Operation operation, final StringBuilder builder) 1045 { 1046 appendResponseControls(operation, builder); 1047 for (final AdditionalLogItem item : operation.getAdditionalLogItems()) 1048 { 1049 builder.append(' '); 1050 item.toString(builder); 1051 } 1052 } 1053}