001/*
002 * CDDL HEADER START
003 *
004 * The contents of this file are subject to the terms of the
005 * Common Development and Distribution License, Version 1.0 only
006 * (the "License").  You may not use this file except in compliance
007 * with the License.
008 *
009 * You can obtain a copy of the license at legal-notices/CDDLv1_0.txt
010 * or http://forgerock.org/license/CDDLv1.0.html.
011 * See the License for the specific language governing permissions
012 * and limitations under the License.
013 *
014 * When distributing Covered Code, include this CDDL HEADER in each
015 * file and include the License file at legal-notices/CDDLv1_0.txt.
016 * If applicable, add the following below this CDDL HEADER, with the
017 * fields enclosed by brackets "[]" replaced with your own identifying
018 * information:
019 *      Portions Copyright [yyyy] [name of copyright owner]
020 *
021 * CDDL HEADER END
022 *
023 *
024 *      Copyright 2006-2009 Sun Microsystems, Inc.
025 *      Portions Copyright 2011-2015 ForgeRock AS
026 */
027package org.opends.server.loggers;
028
029import static org.opends.messages.ConfigMessages.*;
030import static org.opends.server.util.StaticUtils.*;
031
032import java.io.File;
033import java.io.IOException;
034import java.text.SimpleDateFormat;
035import java.util.Iterator;
036import java.util.List;
037import java.util.Set;
038
039import org.forgerock.i18n.LocalizableMessage;
040import org.forgerock.i18n.LocalizableMessageBuilder;
041import org.forgerock.opendj.config.server.ConfigChangeResult;
042import org.forgerock.opendj.config.server.ConfigException;
043import org.forgerock.opendj.ldap.ByteString;
044import org.forgerock.opendj.ldap.ResultCode;
045import org.opends.server.admin.server.ConfigurationChangeListener;
046import org.opends.server.admin.std.meta.FileBasedAccessLogPublisherCfgDefn.LogFormat;
047import org.opends.server.admin.std.server.FileBasedAccessLogPublisherCfg;
048import org.opends.server.api.ClientConnection;
049import org.opends.server.api.ExtendedOperationHandler;
050import org.opends.server.core.*;
051import org.opends.server.types.*;
052import org.opends.server.util.TimeThread;
053
054/**
055 * This class provides the implementation of the access logger used by the
056 * directory server.
057 */
058public final class TextAccessLogPublisher extends
059    AbstractTextAccessLogPublisher<FileBasedAccessLogPublisherCfg> implements
060    ConfigurationChangeListener<FileBasedAccessLogPublisherCfg>
061{
062
063  /**
064   * The category to use when logging responses.
065   */
066  private static final String CATEGORY_RESPONSE = "RES";
067
068  /**
069   * The category to use when logging requests.
070   */
071  private static final String CATEGORY_REQUEST = "REQ";
072
073
074
075  /**
076   * Returns an instance of the text access log publisher that will print all
077   * messages to the provided writer. This is used to print the messages to the
078   * console when the server starts up.
079   *
080   * @param writer
081   *          The text writer where the message will be written to.
082   * @param suppressInternal
083   *          Indicates whether to suppress internal operations.
084   * @return The instance of the text error log publisher that will print all
085   *         messages to standard out.
086   */
087  public static TextAccessLogPublisher getStartupTextAccessPublisher(
088      final TextWriter writer, final boolean suppressInternal)
089  {
090    final TextAccessLogPublisher startupPublisher =
091      new TextAccessLogPublisher();
092    startupPublisher.writer = writer;
093    startupPublisher.buildFilters(suppressInternal);
094    return startupPublisher;
095  }
096
097
098
099  private TextWriter writer;
100  private FileBasedAccessLogPublisherCfg cfg;
101  private boolean isCombinedMode;
102  private boolean includeControlOIDs;
103  private String timeStampFormat = "dd/MMM/yyyy:HH:mm:ss Z";
104
105
106
107  /** {@inheritDoc} */
108  @Override
109  public ConfigChangeResult applyConfigurationChange(
110      final FileBasedAccessLogPublisherCfg config)
111  {
112    final ConfigChangeResult ccr = new ConfigChangeResult();
113
114    final File logFile = getFileForPath(config.getLogFile());
115    final FileNamingPolicy fnPolicy = new TimeStampNaming(logFile);
116    try
117    {
118      final FilePermission perm = FilePermission.decodeUNIXMode(config
119          .getLogFilePermissions());
120
121      final boolean writerAutoFlush = config.isAutoFlush()
122          && !config.isAsynchronous();
123
124      TextWriter currentWriter;
125      // Determine the writer we are using. If we were writing
126      // asynchronously, we need to modify the underlying writer.
127      if (writer instanceof AsynchronousTextWriter)
128      {
129        currentWriter = ((AsynchronousTextWriter) writer).getWrappedWriter();
130      }
131      else if (writer instanceof ParallelTextWriter)
132      {
133        currentWriter = ((ParallelTextWriter) writer).getWrappedWriter();
134      }
135      else
136      {
137        currentWriter = writer;
138      }
139
140      if (currentWriter instanceof MultifileTextWriter)
141      {
142        final MultifileTextWriter mfWriter =
143          (MultifileTextWriter) currentWriter;
144
145        mfWriter.setNamingPolicy(fnPolicy);
146        mfWriter.setFilePermissions(perm);
147        mfWriter.setAppend(config.isAppend());
148        mfWriter.setAutoFlush(writerAutoFlush);
149        mfWriter.setBufferSize((int) config.getBufferSize());
150        mfWriter.setInterval(config.getTimeInterval());
151
152        mfWriter.removeAllRetentionPolicies();
153        mfWriter.removeAllRotationPolicies();
154
155        for (final DN dn : config.getRotationPolicyDNs())
156        {
157          mfWriter.addRotationPolicy(DirectoryServer.getRotationPolicy(dn));
158        }
159
160        for (final DN dn : config.getRetentionPolicyDNs())
161        {
162          mfWriter.addRetentionPolicy(DirectoryServer.getRetentionPolicy(dn));
163        }
164
165        if (writer instanceof AsynchronousTextWriter
166            && !config.isAsynchronous())
167        {
168          // The asynchronous setting is being turned off.
169          final AsynchronousTextWriter asyncWriter = (AsynchronousTextWriter) writer;
170          writer = mfWriter;
171          asyncWriter.shutdown(false);
172        }
173
174        if (writer instanceof ParallelTextWriter && !config.isAsynchronous())
175        {
176          // The asynchronous setting is being turned off.
177          final ParallelTextWriter asyncWriter = (ParallelTextWriter) writer;
178          writer = mfWriter;
179          asyncWriter.shutdown(false);
180        }
181
182        if (!(writer instanceof AsynchronousTextWriter)
183            && config.isAsynchronous())
184        {
185          // The asynchronous setting is being turned on.
186          writer = new AsynchronousTextWriter("Asynchronous Text Writer for " + config.dn(),
187          config.getQueueSize(), config.isAutoFlush(), mfWriter);
188        }
189
190        if (!(writer instanceof ParallelTextWriter) && config.isAsynchronous())
191        {
192          // The asynchronous setting is being turned on.
193          writer = new ParallelTextWriter("Parallel Text Writer for " + config.dn(),
194              config.isAutoFlush(), mfWriter);
195        }
196
197        if (cfg.isAsynchronous() && config.isAsynchronous()
198            && cfg.getQueueSize() != config.getQueueSize())
199        {
200          ccr.setAdminActionRequired(true);
201        }
202
203        if (!config.getLogRecordTimeFormat().equals(timeStampFormat))
204        {
205          TimeThread.removeUserDefinedFormatter(timeStampFormat);
206          timeStampFormat = config.getLogRecordTimeFormat();
207        }
208
209        cfg = config;
210        isCombinedMode = cfg.getLogFormat() == LogFormat.COMBINED;
211        includeControlOIDs = cfg.isLogControlOids();
212      }
213    }
214    catch (final Exception e)
215    {
216      ccr.setResultCode(DirectoryServer.getServerErrorResultCode());
217      ccr.addMessage(ERR_CONFIG_LOGGING_CANNOT_CREATE_WRITER.get(
218          config.dn(), stackTraceToSingleLineString(e)));
219    }
220
221    return ccr;
222  }
223
224
225
226  /** {@inheritDoc} */
227  @Override
228  public void initializeLogPublisher(final FileBasedAccessLogPublisherCfg cfg, ServerContext serverContext)
229      throws ConfigException, InitializationException
230  {
231    final File logFile = getFileForPath(cfg.getLogFile());
232    final FileNamingPolicy fnPolicy = new TimeStampNaming(logFile);
233
234    try
235    {
236      final FilePermission perm = FilePermission.decodeUNIXMode(cfg
237          .getLogFilePermissions());
238
239      final LogPublisherErrorHandler errorHandler =
240        new LogPublisherErrorHandler(cfg.dn());
241
242      final boolean writerAutoFlush = cfg.isAutoFlush()
243          && !cfg.isAsynchronous();
244
245      final MultifileTextWriter theWriter = new MultifileTextWriter(
246          "Multifile Text Writer for " + cfg.dn(),
247          cfg.getTimeInterval(), fnPolicy, perm, errorHandler, "UTF-8",
248          writerAutoFlush, cfg.isAppend(), (int) cfg.getBufferSize());
249
250      // Validate retention and rotation policies.
251      for (final DN dn : cfg.getRotationPolicyDNs())
252      {
253        theWriter.addRotationPolicy(DirectoryServer.getRotationPolicy(dn));
254      }
255
256      for (final DN dn : cfg.getRetentionPolicyDNs())
257      {
258        theWriter.addRetentionPolicy(DirectoryServer.getRetentionPolicy(dn));
259      }
260
261      if (cfg.isAsynchronous())
262      {
263        if (cfg.getQueueSize() > 0)
264        {
265          this.writer = new AsynchronousTextWriter(
266              "Asynchronous Text Writer for " + cfg.dn(),
267              cfg.getQueueSize(), cfg.isAutoFlush(), theWriter);
268        }
269        else
270        {
271          this.writer = new ParallelTextWriter("Parallel Text Writer for " + cfg.dn(),
272              cfg.isAutoFlush(), theWriter);
273        }
274      }
275      else
276      {
277        this.writer = theWriter;
278      }
279    }
280    catch (final DirectoryException e)
281    {
282      throw new InitializationException(
283          ERR_CONFIG_LOGGING_CANNOT_CREATE_WRITER.get(cfg.dn(), e), e);
284    }
285    catch (final IOException e)
286    {
287      throw new InitializationException(
288          ERR_CONFIG_LOGGING_CANNOT_OPEN_FILE.get(logFile, cfg.dn(), e), e);
289
290    }
291
292    initializeFilters(cfg);
293
294    this.cfg = cfg;
295    isCombinedMode = cfg.getLogFormat() == LogFormat.COMBINED;
296    includeControlOIDs = cfg.isLogControlOids();
297    timeStampFormat = cfg.getLogRecordTimeFormat();
298
299    cfg.addFileBasedAccessChangeListener(this);
300  }
301
302
303
304  /** {@inheritDoc} */
305  @Override
306  public boolean isConfigurationAcceptable(
307      final FileBasedAccessLogPublisherCfg configuration,
308      final List<LocalizableMessage> unacceptableReasons)
309  {
310    return isFilterConfigurationAcceptable(configuration, unacceptableReasons)
311        && isConfigurationChangeAcceptable(configuration, unacceptableReasons);
312  }
313
314
315
316  /** {@inheritDoc} */
317  @Override
318  public boolean isConfigurationChangeAcceptable(
319      final FileBasedAccessLogPublisherCfg config,
320      final List<LocalizableMessage> unacceptableReasons)
321  {
322    // Validate the time-stamp formatter.
323    final String formatString = config.getLogRecordTimeFormat();
324    try
325    {
326       new SimpleDateFormat(formatString);
327    }
328    catch (final Exception e)
329    {
330      final LocalizableMessage message = ERR_CONFIG_LOGGING_INVALID_TIME_FORMAT.get(formatString);
331      unacceptableReasons.add(message);
332      return false;
333    }
334
335    // Make sure the permission is valid.
336    try
337    {
338      final FilePermission filePerm = FilePermission.decodeUNIXMode(config
339          .getLogFilePermissions());
340      if (!filePerm.isOwnerWritable())
341      {
342        final LocalizableMessage message = ERR_CONFIG_LOGGING_INSANE_MODE.get(config
343            .getLogFilePermissions());
344        unacceptableReasons.add(message);
345        return false;
346      }
347    }
348    catch (final DirectoryException e)
349    {
350      unacceptableReasons.add(ERR_CONFIG_LOGGING_MODE_INVALID.get(config.getLogFilePermissions(), e));
351      return false;
352    }
353
354    return true;
355  }
356
357
358
359  /**
360   * Writes a message to the access logger with information about the abandon
361   * request associated with the provided abandon operation.
362   *
363   * @param abandonOperation
364   *          The abandon operation containing the information to use to log the
365   *          abandon request.
366   */
367  @Override
368  public void logAbandonRequest(final AbandonOperation abandonOperation)
369  {
370    if (isCombinedMode || !isRequestLoggable(abandonOperation))
371    {
372      return;
373    }
374
375    final StringBuilder buffer = new StringBuilder(100);
376    appendHeader(abandonOperation, "ABANDON", CATEGORY_REQUEST, buffer);
377    appendAbandonRequest(abandonOperation, buffer);
378    writer.writeRecord(buffer.toString());
379  }
380
381
382
383  /**
384   * Writes a message to the access logger with information about the result of
385   * the provided abandon operation.
386   *
387   * @param abandonOperation
388   *          The abandon operation containing the information to use to log the
389   *          abandon request.
390   */
391  @Override
392  public void logAbandonResult(final AbandonOperation abandonOperation)
393  {
394    if (!isResponseLoggable(abandonOperation))
395    {
396      return;
397    }
398
399    final StringBuilder buffer = new StringBuilder(100);
400    appendHeader(abandonOperation, "ABANDON", CATEGORY_RESPONSE, buffer);
401    if (isCombinedMode)
402    {
403      appendAbandonRequest(abandonOperation, buffer);
404    }
405    appendResultCodeAndMessage(buffer, abandonOperation);
406
407    logAdditionalLogItems(abandonOperation, buffer);
408
409    appendEtime(buffer, abandonOperation);
410
411    writer.writeRecord(buffer.toString());
412  }
413
414
415
416  /**
417   * Writes a message to the access logger with information about the add
418   * request associated with the provided add operation.
419   *
420   * @param addOperation
421   *          The add operation containing the information to use to log the add
422   *          request.
423   */
424  @Override
425  public void logAddRequest(final AddOperation addOperation)
426  {
427    if (isCombinedMode || !isRequestLoggable(addOperation))
428    {
429      return;
430    }
431
432    final StringBuilder buffer = new StringBuilder(100);
433    appendHeader(addOperation, "ADD", CATEGORY_REQUEST, buffer);
434    appendAddRequest(addOperation, buffer);
435    writer.writeRecord(buffer.toString());
436  }
437
438
439
440  /**
441   * Writes a message to the access logger with information about the add
442   * response associated with the provided add operation.
443   *
444   * @param addOperation
445   *          The add operation containing the information to use to log the add
446   *          response.
447   */
448  @Override
449  public void logAddResponse(final AddOperation addOperation)
450  {
451    if (!isResponseLoggable(addOperation))
452    {
453      return;
454    }
455
456    final StringBuilder buffer = new StringBuilder(100);
457    appendHeader(addOperation, "ADD", CATEGORY_RESPONSE, buffer);
458    if (isCombinedMode)
459    {
460      appendAddRequest(addOperation, buffer);
461    }
462    appendResultCodeAndMessage(buffer, addOperation);
463
464    logAdditionalLogItems(addOperation, buffer);
465
466    appendLabelIfNotNull(buffer, "authzDN", addOperation
467        .getProxiedAuthorizationDN());
468
469    appendEtime(buffer, addOperation);
470
471    writer.writeRecord(buffer.toString());
472  }
473
474
475
476  /**
477   * Writes a message to the access logger with information about the bind
478   * request associated with the provided bind operation.
479   *
480   * @param bindOperation
481   *          The bind operation with the information to use to log the bind
482   *          request.
483   */
484  @Override
485  public void logBindRequest(final BindOperation bindOperation)
486  {
487    if (isCombinedMode || !isRequestLoggable(bindOperation))
488    {
489      return;
490    }
491
492    final StringBuilder buffer = new StringBuilder(100);
493    appendHeader(bindOperation, "BIND", CATEGORY_REQUEST, buffer);
494    appendBindRequest(bindOperation, buffer);
495    writer.writeRecord(buffer.toString());
496  }
497
498
499
500  /**
501   * Writes a message to the access logger with information about the bind
502   * response associated with the provided bind operation.
503   *
504   * @param bindOperation
505   *          The bind operation containing the information to use to log the
506   *          bind response.
507   */
508  @Override
509  public void logBindResponse(final BindOperation bindOperation)
510  {
511    if (!isResponseLoggable(bindOperation))
512    {
513      return;
514    }
515
516    final StringBuilder buffer = new StringBuilder(100);
517    appendHeader(bindOperation, "BIND", CATEGORY_RESPONSE, buffer);
518    if (isCombinedMode)
519    {
520      appendBindRequest(bindOperation, buffer);
521    }
522    appendResultCodeAndMessage(buffer, bindOperation);
523
524    final LocalizableMessage failureMessage = bindOperation.getAuthFailureReason();
525    if (failureMessage != null)
526    {
527      // this code path is mutually exclusive with the if result code is success
528      // down below
529      appendLabel(buffer, "authFailureReason", failureMessage);
530      if (bindOperation.getSASLMechanism() != null
531          && bindOperation.getSASLAuthUserEntry() != null)
532      { // SASL bind and we have successfully found a user entry for auth
533        appendLabel(buffer, "authDN", bindOperation.getSASLAuthUserEntry()
534            .getName());
535      }
536      else
537      { // SASL bind failed to find user entry for auth or simple bind
538        appendLabel(buffer, "authDN", bindOperation.getRawBindDN());
539      }
540    }
541
542    logAdditionalLogItems(bindOperation, buffer);
543
544    if (bindOperation.getResultCode() == ResultCode.SUCCESS)
545    {
546      // this code path is mutually exclusive with the if failure message exist
547      // just above
548      final AuthenticationInfo authInfo = bindOperation.getAuthenticationInfo();
549      if (authInfo != null)
550      {
551        final DN authDN = authInfo.getAuthenticationDN();
552        if (authDN != null)
553        {
554          appendLabel(buffer, "authDN", authDN);
555
556          final DN authzDN = authInfo.getAuthorizationDN();
557          if (!authDN.equals(authzDN))
558          {
559            appendLabel(buffer, "authzDN", authzDN);
560          }
561        }
562        else
563        {
564          buffer.append(" authDN=\"\"");
565        }
566      }
567    }
568
569    appendEtime(buffer, bindOperation);
570
571    writer.writeRecord(buffer.toString());
572  }
573
574
575
576  /**
577   * Writes a message to the access logger with information about the compare
578   * request associated with the provided compare operation.
579   *
580   * @param compareOperation
581   *          The compare operation containing the information to use to log the
582   *          compare request.
583   */
584  @Override
585  public void logCompareRequest(final CompareOperation compareOperation)
586  {
587    if (isCombinedMode || !isRequestLoggable(compareOperation))
588    {
589      return;
590    }
591
592    final StringBuilder buffer = new StringBuilder(100);
593    appendHeader(compareOperation, "COMPARE", CATEGORY_REQUEST, buffer);
594    appendCompareRequest(compareOperation, buffer);
595    writer.writeRecord(buffer.toString());
596  }
597
598
599
600  /**
601   * Writes a message to the access logger with information about the compare
602   * response associated with the provided compare operation.
603   *
604   * @param compareOperation
605   *          The compare operation containing the information to use to log the
606   *          compare response.
607   */
608  @Override
609  public void logCompareResponse(final CompareOperation compareOperation)
610  {
611    if (!isResponseLoggable(compareOperation))
612    {
613      return;
614    }
615
616    final StringBuilder buffer = new StringBuilder(100);
617    appendHeader(compareOperation, "COMPARE", CATEGORY_RESPONSE, buffer);
618    if (isCombinedMode)
619    {
620      appendCompareRequest(compareOperation, buffer);
621    }
622    appendResultCodeAndMessage(buffer, compareOperation);
623
624    logAdditionalLogItems(compareOperation, buffer);
625
626    appendLabelIfNotNull(buffer, "authzDN", compareOperation
627        .getProxiedAuthorizationDN());
628
629    appendEtime(buffer, compareOperation);
630
631    writer.writeRecord(buffer.toString());
632  }
633
634
635
636  /**
637   * Writes a message to the access logger with information about a new client
638   * connection that has been established, regardless of whether it will be
639   * immediately terminated.
640   *
641   * @param clientConnection
642   *          The client connection that has been established.
643   */
644  @Override
645  public void logConnect(final ClientConnection clientConnection)
646  {
647    if (!isConnectLoggable(clientConnection))
648    {
649      return;
650    }
651
652    final long connectionID = clientConnection.getConnectionID();
653    final StringBuilder buffer = new StringBuilder(100);
654    buffer.append('[');
655    buffer.append(TimeThread.getUserDefinedTime(timeStampFormat));
656    buffer.append(']');
657    buffer.append(" CONNECT conn=");
658    buffer.append(connectionID);
659    buffer.append(" from=");
660    buffer.append(clientConnection.getClientHostPort());
661    buffer.append(" to=");
662    buffer.append(clientConnection.getServerHostPort());
663    buffer.append(" protocol=");
664    buffer.append(clientConnection.getProtocol());
665
666    writer.writeRecord(buffer.toString());
667  }
668
669
670
671  /**
672   * Writes a message to the access logger with information about the delete
673   * request associated with the provided delete operation.
674   *
675   * @param deleteOperation
676   *          The delete operation with the information to use to log the delete
677   *          request.
678   */
679  @Override
680  public void logDeleteRequest(final DeleteOperation deleteOperation)
681  {
682    if (isCombinedMode || !isRequestLoggable(deleteOperation))
683    {
684      return;
685    }
686
687    final StringBuilder buffer = new StringBuilder(100);
688    appendHeader(deleteOperation, "DELETE", CATEGORY_REQUEST, buffer);
689    appendDeleteRequest(deleteOperation, buffer);
690    writer.writeRecord(buffer.toString());
691  }
692
693
694
695  /**
696   * Writes a message to the access logger with information about the delete
697   * response associated with the provided delete operation.
698   *
699   * @param deleteOperation
700   *          The delete operation containing the information to use to log the
701   *          delete response.
702   */
703  @Override
704  public void logDeleteResponse(final DeleteOperation deleteOperation)
705  {
706    if (!isResponseLoggable(deleteOperation))
707    {
708      return;
709    }
710
711    final StringBuilder buffer = new StringBuilder(100);
712    appendHeader(deleteOperation, "DELETE", CATEGORY_RESPONSE, buffer);
713    if (isCombinedMode)
714    {
715      appendDeleteRequest(deleteOperation, buffer);
716    }
717    appendResultCodeAndMessage(buffer, deleteOperation);
718
719    logAdditionalLogItems(deleteOperation, buffer);
720
721    appendLabelIfNotNull(buffer, "authzDN", deleteOperation
722        .getProxiedAuthorizationDN());
723
724    appendEtime(buffer, deleteOperation);
725
726    writer.writeRecord(buffer.toString());
727  }
728
729
730
731  /**
732   * Writes a message to the access logger with information about the
733   * termination of an existing client connection.
734   *
735   * @param clientConnection
736   *          The client connection that has been terminated.
737   * @param disconnectReason
738   *          A generic disconnect reason for the connection termination.
739   * @param message
740   *          A human-readable message that can provide additional information
741   *          about the disconnect.
742   */
743  @Override
744  public void logDisconnect(final ClientConnection clientConnection,
745      final DisconnectReason disconnectReason, final LocalizableMessage message)
746  {
747    if (!isDisconnectLoggable(clientConnection))
748    {
749      return;
750    }
751
752    final long connectionID = clientConnection.getConnectionID();
753    final StringBuilder buffer = new StringBuilder(100);
754    buffer.append('[');
755    buffer.append(TimeThread.getUserDefinedTime(timeStampFormat));
756    buffer.append(']');
757    buffer.append(" DISCONNECT conn=");
758    buffer.append(connectionID);
759    appendLabel(buffer, "reason", disconnectReason);
760    appendLabelIfNotNull(buffer, "msg", message);
761
762    writer.writeRecord(buffer.toString());
763  }
764
765
766
767  /**
768   * Writes a message to the access logger with information about the extended
769   * request associated with the provided extended operation.
770   *
771   * @param extendedOperation
772   *          The extended operation containing the information to use to log
773   *          the extended request.
774   */
775  @Override
776  public void logExtendedRequest(final ExtendedOperation extendedOperation)
777  {
778    if (isCombinedMode || !isRequestLoggable(extendedOperation))
779    {
780      return;
781    }
782
783    final StringBuilder buffer = new StringBuilder(100);
784    appendHeader(extendedOperation, "EXTENDED", CATEGORY_REQUEST, buffer);
785    appendExtendedRequest(extendedOperation, buffer);
786    writer.writeRecord(buffer.toString());
787  }
788
789
790
791  /**
792   * Writes a message to the access logger with information about the extended
793   * response associated with the provided extended operation.
794   *
795   * @param extendedOperation
796   *          The extended operation containing the info to use to log the
797   *          extended response.
798   */
799  @Override
800  public void logExtendedResponse(final ExtendedOperation extendedOperation)
801  {
802    if (!isResponseLoggable(extendedOperation))
803    {
804      return;
805    }
806
807    final StringBuilder buffer = new StringBuilder(100);
808    appendHeader(extendedOperation, "EXTENDED", CATEGORY_RESPONSE, buffer);
809    if (isCombinedMode)
810    {
811      appendExtendedRequest(extendedOperation, buffer);
812    }
813
814    final String oid = extendedOperation.getResponseOID();
815    if (oid != null)
816    {
817      final ExtendedOperationHandler<?> extOpHandler = DirectoryServer
818          .getExtendedOperationHandler(oid);
819      if (extOpHandler != null)
820      {
821        String name = extOpHandler.getExtendedOperationName();
822        appendLabelIfNotNull(buffer, "name", name);
823      }
824      appendLabel(buffer, "oid", oid);
825    }
826    appendResultCodeAndMessage(buffer, extendedOperation);
827
828    logAdditionalLogItems(extendedOperation, buffer);
829
830    appendEtime(buffer, extendedOperation);
831
832    writer.writeRecord(buffer.toString());
833  }
834
835
836
837  /**
838   * Writes a message to the access logger with information about the modify DN
839   * request associated with the provided modify DN operation.
840   *
841   * @param modifyDNOperation
842   *          The modify DN operation containing the info to use to log the
843   *          modify DN request.
844   */
845  @Override
846  public void logModifyDNRequest(final ModifyDNOperation modifyDNOperation)
847  {
848    if (isCombinedMode || !isRequestLoggable(modifyDNOperation))
849    {
850      return;
851    }
852
853    final StringBuilder buffer = new StringBuilder(100);
854    appendHeader(modifyDNOperation, "MODIFYDN", CATEGORY_REQUEST, buffer);
855    appendModifyDNRequest(modifyDNOperation, buffer);
856    writer.writeRecord(buffer.toString());
857  }
858
859
860
861  /**
862   * Writes a message to the access logger with information about the modify DN
863   * response associated with the provided modify DN operation.
864   *
865   * @param modifyDNOperation
866   *          The modify DN operation containing the information to use to log
867   *          the modify DN response.
868   */
869  @Override
870  public void logModifyDNResponse(final ModifyDNOperation modifyDNOperation)
871  {
872    if (!isResponseLoggable(modifyDNOperation))
873    {
874      return;
875    }
876
877    final StringBuilder buffer = new StringBuilder(100);
878    appendHeader(modifyDNOperation, "MODIFYDN", CATEGORY_RESPONSE, buffer);
879    if (isCombinedMode)
880    {
881      appendModifyDNRequest(modifyDNOperation, buffer);
882    }
883    appendResultCodeAndMessage(buffer, modifyDNOperation);
884
885    logAdditionalLogItems(modifyDNOperation, buffer);
886
887    appendLabelIfNotNull(buffer, "authzDN", modifyDNOperation
888        .getProxiedAuthorizationDN());
889
890    appendEtime(buffer, modifyDNOperation);
891
892    writer.writeRecord(buffer.toString());
893  }
894
895
896
897  /**
898   * Writes a message to the access logger with information about the modify
899   * request associated with the provided modify operation.
900   *
901   * @param modifyOperation
902   *          The modify operation containing the information to use to log the
903   *          modify request.
904   */
905  @Override
906  public void logModifyRequest(final ModifyOperation modifyOperation)
907  {
908    if (isCombinedMode || !isRequestLoggable(modifyOperation))
909    {
910      return;
911    }
912
913    final StringBuilder buffer = new StringBuilder(100);
914    appendHeader(modifyOperation, "MODIFY", CATEGORY_REQUEST, buffer);
915    appendModifyRequest(modifyOperation, buffer);
916    writer.writeRecord(buffer.toString());
917  }
918
919
920
921  /**
922   * Writes a message to the access logger with information about the modify
923   * response associated with the provided modify operation.
924   *
925   * @param modifyOperation
926   *          The modify operation containing the information to use to log the
927   *          modify response.
928   */
929  @Override
930  public void logModifyResponse(final ModifyOperation modifyOperation)
931  {
932    if (!isResponseLoggable(modifyOperation))
933    {
934      return;
935    }
936
937    final StringBuilder buffer = new StringBuilder(100);
938    appendHeader(modifyOperation, "MODIFY", CATEGORY_RESPONSE, buffer);
939    if (isCombinedMode)
940    {
941      appendModifyRequest(modifyOperation, buffer);
942    }
943    appendResultCodeAndMessage(buffer, modifyOperation);
944
945    logAdditionalLogItems(modifyOperation, buffer);
946
947    appendLabelIfNotNull(buffer, "authzDN", modifyOperation
948        .getProxiedAuthorizationDN());
949
950    appendEtime(buffer, modifyOperation);
951
952    writer.writeRecord(buffer.toString());
953  }
954
955
956
957  /**
958   * Writes a message to the access logger with information about the search
959   * request associated with the provided search operation.
960   *
961   * @param searchOperation
962   *          The search operation containing the info to use to log the search
963   *          request.
964   */
965  @Override
966  public void logSearchRequest(final SearchOperation searchOperation)
967  {
968    if (isCombinedMode || !isRequestLoggable(searchOperation))
969    {
970      return;
971    }
972
973    final StringBuilder buffer = new StringBuilder(192);
974    appendHeader(searchOperation, "SEARCH", CATEGORY_REQUEST, buffer);
975    appendSearchRequest(searchOperation, buffer);
976    writer.writeRecord(buffer.toString());
977  }
978
979
980
981  /**
982   * Writes a message to the access logger with information about the completion
983   * of the provided search operation.
984   *
985   * @param searchOperation
986   *          The search operation containing the information to use to log the
987   *          search result done message.
988   */
989  @Override
990  public void logSearchResultDone(final SearchOperation searchOperation)
991  {
992    if (!isResponseLoggable(searchOperation))
993    {
994      return;
995    }
996
997    final StringBuilder buffer = new StringBuilder(128);
998    appendHeader(searchOperation, "SEARCH", CATEGORY_RESPONSE, buffer);
999    if (isCombinedMode)
1000    {
1001      appendSearchRequest(searchOperation, buffer);
1002    }
1003    appendResultCodeAndMessage(buffer, searchOperation);
1004
1005    buffer.append(" nentries=");
1006    buffer.append(searchOperation.getEntriesSent());
1007
1008    logAdditionalLogItems(searchOperation, buffer);
1009
1010    appendLabelIfNotNull(buffer, "authzDN", searchOperation
1011        .getProxiedAuthorizationDN());
1012
1013    appendEtime(buffer, searchOperation);
1014
1015    writer.writeRecord(buffer.toString());
1016  }
1017
1018
1019
1020  /**
1021   * Writes a message to the access logger with information about the unbind
1022   * request associated with the provided unbind operation.
1023   *
1024   * @param unbindOperation
1025   *          The unbind operation containing the info to use to log the unbind
1026   *          request.
1027   */
1028  @Override
1029  public void logUnbind(final UnbindOperation unbindOperation)
1030  {
1031    if (!isRequestLoggable(unbindOperation))
1032    {
1033      return;
1034    }
1035
1036    final StringBuilder buffer = new StringBuilder(100);
1037    appendHeader(unbindOperation, "UNBIND", CATEGORY_REQUEST, buffer);
1038    if (unbindOperation.isSynchronizationOperation())
1039    {
1040      buffer.append(" type=synchronization");
1041    }
1042
1043    writer.writeRecord(buffer.toString());
1044  }
1045
1046
1047
1048  /** {@inheritDoc} */
1049  @Override
1050  protected void close0()
1051  {
1052    writer.shutdown();
1053    TimeThread.removeUserDefinedFormatter(timeStampFormat);
1054    if (cfg != null)
1055    {
1056      cfg.removeFileBasedAccessChangeListener(this);
1057    }
1058  }
1059
1060
1061
1062  private void appendAbandonRequest(final AbandonOperation abandonOperation,
1063      final StringBuilder buffer)
1064  {
1065    buffer.append(" idToAbandon=");
1066    buffer.append(abandonOperation.getIDToAbandon());
1067    appendRequestControls(abandonOperation, buffer);
1068    if (abandonOperation.isSynchronizationOperation())
1069    {
1070      buffer.append(" type=synchronization");
1071    }
1072  }
1073
1074
1075
1076  private void appendAddRequest(final AddOperation addOperation,
1077      final StringBuilder buffer)
1078  {
1079    appendLabel(buffer, "dn", addOperation.getRawEntryDN());
1080    appendRequestControls(addOperation, buffer);
1081    if (addOperation.isSynchronizationOperation())
1082    {
1083      buffer.append(" type=synchronization");
1084    }
1085  }
1086
1087
1088
1089  private void appendBindRequest(final BindOperation bindOperation,
1090      final StringBuilder buffer)
1091  {
1092    final String protocolVersion = bindOperation.getProtocolVersion();
1093    if (protocolVersion != null)
1094    {
1095      buffer.append(" version=");
1096      buffer.append(protocolVersion);
1097    }
1098
1099    switch (bindOperation.getAuthenticationType())
1100    {
1101    case SIMPLE:
1102      buffer.append(" type=SIMPLE");
1103      break;
1104    case SASL:
1105      buffer.append(" type=SASL mechanism=");
1106      buffer.append(bindOperation.getSASLMechanism());
1107      break;
1108    default:
1109      buffer.append(" type=");
1110      buffer.append(bindOperation.getAuthenticationType());
1111      break;
1112    }
1113
1114    appendLabel(buffer, "dn", bindOperation.getRawBindDN());
1115    appendRequestControls(bindOperation, buffer);
1116    if (bindOperation.isSynchronizationOperation())
1117    {
1118      buffer.append(" type=synchronization");
1119    }
1120  }
1121
1122
1123
1124  private void appendCompareRequest(final CompareOperation compareOperation,
1125      final StringBuilder buffer)
1126  {
1127    appendLabel(buffer, "dn", compareOperation.getRawEntryDN());
1128    buffer.append(" attr=");
1129    buffer.append(compareOperation.getAttributeType().getNameOrOID());
1130    appendRequestControls(compareOperation, buffer);
1131    if (compareOperation.isSynchronizationOperation())
1132    {
1133      buffer.append(" type=synchronization");
1134    }
1135  }
1136
1137
1138
1139  private void appendDeleteRequest(final DeleteOperation deleteOperation,
1140      final StringBuilder buffer)
1141  {
1142    appendLabel(buffer, "dn", deleteOperation.getRawEntryDN());
1143    appendRequestControls(deleteOperation, buffer);
1144    if (deleteOperation.isSynchronizationOperation())
1145    {
1146      buffer.append(" type=synchronization");
1147    }
1148  }
1149
1150
1151
1152  private void appendExtendedRequest(final ExtendedOperation extendedOperation,
1153      final StringBuilder buffer)
1154  {
1155    final String oid = extendedOperation.getRequestOID();
1156    final ExtendedOperationHandler<?> extOpHandler = DirectoryServer
1157        .getExtendedOperationHandler(oid);
1158    if (extOpHandler != null)
1159    {
1160      final String name = extOpHandler.getExtendedOperationName();
1161      appendLabelIfNotNull(buffer, "name", name);
1162    }
1163    appendLabel(buffer, "oid", oid);
1164    appendRequestControls(extendedOperation, buffer);
1165    if (extendedOperation.isSynchronizationOperation())
1166    {
1167      buffer.append(" type=synchronization");
1168    }
1169  }
1170
1171
1172
1173  private void appendLabel(final StringBuilder buffer, final String label,
1174      final Object obj)
1175  {
1176    buffer.append(' ').append(label).append("=\"");
1177    if (obj != null)
1178    {
1179      buffer.append(obj);
1180    }
1181    buffer.append('\"');
1182  }
1183
1184  private void appendLabelIfNotNull(final StringBuilder buffer,
1185      final String label, final Object obj)
1186  {
1187    if (obj != null)
1188    {
1189      appendLabel(buffer, label, obj);
1190    }
1191  }
1192
1193  private void appendResultCodeAndMessage(StringBuilder buffer,
1194      Operation operation)
1195  {
1196    buffer.append(" result=");
1197    buffer.append(operation.getResultCode().intValue());
1198
1199    final LocalizableMessageBuilder msg = operation.getErrorMessage();
1200    if (msg != null && msg.length() > 0)
1201    {
1202      appendLabel(buffer, "message", msg);
1203    }
1204
1205    if (operation.getMaskedResultCode() != null)
1206    {
1207      buffer.append(" maskedResult=");
1208      buffer.append(operation.getMaskedResultCode().intValue());
1209    }
1210    final LocalizableMessageBuilder maskedMsg = operation.getMaskedErrorMessage();
1211    if (maskedMsg != null && maskedMsg.length() > 0)
1212    {
1213      appendLabel(buffer, "maskedMessage", maskedMsg);
1214    }
1215  }
1216
1217  private void appendEtime(final StringBuilder buffer,
1218      final Operation operation)
1219  {
1220    buffer.append(" etime=");
1221    // the server can be configured to log processing time as nanos xor millis
1222    long etime = operation.getProcessingNanoTime();
1223    if (etime <= -1)
1224    {
1225      // if it is not configured for nanos, then use millis.
1226      etime = operation.getProcessingTime();
1227    }
1228    buffer.append(etime);
1229  }
1230
1231  /**
1232   * Appends the common log header information to the provided buffer.
1233   */
1234  private void appendHeader(final Operation operation, final String opType,
1235      final String category, final StringBuilder buffer)
1236  {
1237    buffer.append('[');
1238    buffer.append(TimeThread.getUserDefinedTime(timeStampFormat));
1239    buffer.append("] ");
1240    buffer.append(opType);
1241    if (!isCombinedMode)
1242    {
1243      buffer.append(' ');
1244      buffer.append(category);
1245    }
1246    buffer.append(" conn=");
1247    buffer.append(operation.getConnectionID());
1248    buffer.append(" op=");
1249    buffer.append(operation.getOperationID());
1250    buffer.append(" msgID=");
1251    buffer.append(operation.getMessageID());
1252  }
1253
1254
1255
1256  private void appendModifyDNRequest(final ModifyDNOperation modifyDNOperation,
1257      final StringBuilder buffer)
1258  {
1259    appendLabel(buffer, "dn", modifyDNOperation.getRawEntryDN());
1260    appendLabel(buffer, "newRDN", modifyDNOperation.getRawNewRDN());
1261    appendLabel(buffer, "deleteOldRDN", modifyDNOperation.deleteOldRDN());
1262
1263    final ByteString newSuperior = modifyDNOperation.getRawNewSuperior();
1264    appendLabelIfNotNull(buffer, "newSuperior", newSuperior);
1265    appendRequestControls(modifyDNOperation, buffer);
1266    if (modifyDNOperation.isSynchronizationOperation())
1267    {
1268      buffer.append(" type=synchronization");
1269    }
1270  }
1271
1272
1273
1274  private void appendModifyRequest(final ModifyOperation modifyOperation,
1275      final StringBuilder buffer)
1276  {
1277    appendLabel(buffer, "dn", modifyOperation.getRawEntryDN());
1278    appendRequestControls(modifyOperation, buffer);
1279    if (modifyOperation.isSynchronizationOperation())
1280    {
1281      buffer.append(" type=synchronization");
1282    }
1283  }
1284
1285
1286
1287  private void appendRequestControls(final Operation operation,
1288      final StringBuilder buffer)
1289  {
1290    if (includeControlOIDs && !operation.getRequestControls().isEmpty())
1291    {
1292      buffer.append(" requestControls=");
1293      boolean isFirst = true;
1294      for (final Control control : operation.getRequestControls())
1295      {
1296        if (!isFirst)
1297        {
1298          buffer.append(",");
1299        }
1300        buffer.append(control.getOID());
1301        isFirst = false;
1302      }
1303    }
1304  }
1305
1306
1307
1308  private void appendResponseControls(final Operation operation,
1309      final StringBuilder buffer)
1310  {
1311    if (includeControlOIDs && !operation.getResponseControls().isEmpty())
1312    {
1313      buffer.append(" responseControls=");
1314      boolean isFirst = true;
1315      for (final Control control : operation.getResponseControls())
1316      {
1317        if (!isFirst)
1318        {
1319          buffer.append(",");
1320        }
1321        buffer.append(control.getOID());
1322        isFirst = false;
1323      }
1324    }
1325  }
1326
1327
1328
1329  private void appendSearchRequest(final SearchOperation searchOperation,
1330      final StringBuilder buffer)
1331  {
1332    appendLabel(buffer, "base", searchOperation.getRawBaseDN());
1333    buffer.append(" scope=");
1334    buffer.append(searchOperation.getScope());
1335    buffer.append(" filter=\"");
1336    searchOperation.getRawFilter().toString(buffer);
1337
1338    final Set<String> attrs = searchOperation.getAttributes();
1339    if (attrs == null || attrs.isEmpty())
1340    {
1341      buffer.append("\" attrs=\"ALL\"");
1342    }
1343    else
1344    {
1345      buffer.append("\" attrs=\"");
1346
1347      final Iterator<String> iterator = attrs.iterator();
1348      buffer.append(iterator.next());
1349      while (iterator.hasNext())
1350      {
1351        buffer.append(",");
1352        buffer.append(iterator.next());
1353      }
1354
1355      buffer.append("\"");
1356    }
1357    appendRequestControls(searchOperation, buffer);
1358    if (searchOperation.isSynchronizationOperation())
1359    {
1360      buffer.append(" type=synchronization");
1361    }
1362  }
1363
1364
1365
1366  /**
1367   * Appends additional log items to the provided builder.
1368   */
1369  private void logAdditionalLogItems(final Operation operation,
1370      final StringBuilder builder)
1371  {
1372    appendResponseControls(operation, builder);
1373    for (final AdditionalLogItem item : operation.getAdditionalLogItems())
1374    {
1375      builder.append(' ');
1376      item.toString(builder);
1377    }
1378  }
1379
1380}