From 3b15a98cb11aa68f681fa7ba0dd793cb56ba02d9 Mon Sep 17 00:00:00 2001
From: Gaetan Boismal <gaetan.boismal@forgerock.com>
Date: Wed, 08 Jun 2016 15:18:05 +0000
Subject: [PATCH] OPENDJ-2955 Add logs to rest2ldap gateway

---
 opendj-rest2ldap-servlet/pom.xml                                                                       |    5 +
 opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/authz/CachedReadConnectionDecorator.java |   38 ++++++++-
 opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/LDAPCollectionResourceProvider.java      |   16 +++
 opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HttpAccessLogFilter.java           |   30 ------
 opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/ErrorLoggerFilter.java                   |   69 +++++++++++++++++
 opendj-rest2ldap-servlet/src/main/webapp/WEB-INF/classes/logging.properties                            |   13 +++
 opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/Rest2LDAPHttpApplication.java            |   13 +-
 pom.xml                                                                                                |    1 
 opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HTTPConnectionHandler.java         |    4 
 9 files changed, 146 insertions(+), 43 deletions(-)

diff --git a/opendj-rest2ldap-servlet/pom.xml b/opendj-rest2ldap-servlet/pom.xml
index bc417cb..4d1b239 100644
--- a/opendj-rest2ldap-servlet/pom.xml
+++ b/opendj-rest2ldap-servlet/pom.xml
@@ -37,6 +37,11 @@
 
   <dependencies>
     <dependency>
+      <groupId>org.slf4j</groupId>
+      <artifactId>slf4j-jdk14</artifactId>
+    </dependency>
+
+    <dependency>
       <groupId>org.forgerock.http</groupId>
       <artifactId>chf-http-servlet</artifactId>
     </dependency>
diff --git a/opendj-rest2ldap-servlet/src/main/webapp/WEB-INF/classes/logging.properties b/opendj-rest2ldap-servlet/src/main/webapp/WEB-INF/classes/logging.properties
new file mode 100644
index 0000000..0c90267
--- /dev/null
+++ b/opendj-rest2ldap-servlet/src/main/webapp/WEB-INF/classes/logging.properties
@@ -0,0 +1,13 @@
+################################################################################################################
+# Tomcat rest2ldap log file handler configuration
+# By default: all rest2ldap logs will end up in ${catalina.base}/logs/rest2ldap.yyyy-MM-dd.log
+# Set the log level to FINEST to enable ldap requests logging.
+# See https://tomcat.apache.org/tomcat-8.0-doc/logging.html for more details about how to configure tomcat logs.
+################################################################################################################
+handlers = 5rest2ldap.org.apache.juli.FileHandler
+
+5rest2ldap.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
+5rest2ldap.org.apache.juli.FileHandler.prefix = rest2ldap.
+
+org.forgerock.opendj.rest2ldap.level = ERROR
+org.forgerock.opendj.rest2ldap.handlers = 5rest2ldap.org.apache.juli.FileHandler
diff --git a/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/ErrorLoggerFilter.java b/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/ErrorLoggerFilter.java
new file mode 100644
index 0000000..7a48749
--- /dev/null
+++ b/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/ErrorLoggerFilter.java
@@ -0,0 +1,69 @@
+/*
+ * The contents of this file are subject to the terms of the Common Development and
+ * Distribution License (the License). You may not use this file except in compliance with the
+ * License.
+ *
+ * You can obtain a copy of the License at legal/CDDLv1.0.txt. See the License for the
+ * specific language governing permission and limitations under the License.
+ *
+ * When distributing Covered Software, include this CDDL Header Notice in each file and include
+ * the License file at legal/CDDLv1.0.txt. If applicable, add the following below the CDDL
+ * Header, with the fields enclosed by brackets [] replaced by your own identifying
+ * information: "Portions Copyright [year] [name of copyright owner]".
+ *
+ * Copyright 2016 ForgeRock AS.
+ */
+package org.forgerock.opendj.rest2ldap;
+
+import static org.forgerock.http.protocol.Responses.newInternalServerError;
+import static org.forgerock.opendj.rest2ldap.Rest2ldapMessages.ERR_ERROR_RESPONSE;
+import static org.forgerock.opendj.rest2ldap.Rest2ldapMessages.ERR_RUNTIME_EXCEPTION;
+
+import org.forgerock.http.Filter;
+import org.forgerock.http.Handler;
+import org.forgerock.http.protocol.Request;
+import org.forgerock.http.protocol.Response;
+import org.forgerock.http.protocol.Status;
+import org.forgerock.i18n.slf4j.LocalizedLogger;
+import org.forgerock.services.context.Context;
+import org.forgerock.util.Function;
+import org.forgerock.util.promise.NeverThrowsException;
+import org.forgerock.util.promise.Promise;
+import org.forgerock.util.promise.ResultHandler;
+
+/** Logs internal server errors and runtime exceptions once the request has been processed. */
+public final class ErrorLoggerFilter implements Filter {
+
+    private static final LocalizedLogger logger = LocalizedLogger.getLoggerForThisClass();
+
+    @Override
+    public Promise<Response, NeverThrowsException> filter(final Context context,
+                                                          final Request request,
+                                                          final Handler next) {
+        return next.handle(context, request)
+                .thenOnResult(new ResultHandler<Response>() {
+                    @Override
+                    public void handleResult(final Response response) {
+                        final Exception cause = response.getCause();
+                        final Status status = response.getStatus();
+                        if (status.isServerError() && cause != null) {
+                            logger.error(ERR_ERROR_RESPONSE,
+                                         toLog(request),
+                                         status.toString(),
+                                         cause.getLocalizedMessage(),
+                                         cause);
+                        }
+                    }
+                }).thenCatchRuntimeException(new Function<RuntimeException, Response, NeverThrowsException>() {
+                    @Override
+                    public Response apply(final RuntimeException e) {
+                        logger.error(ERR_RUNTIME_EXCEPTION, toLog(request), e.getLocalizedMessage(), e);
+                        return newInternalServerError(e);
+                    }
+                });
+    }
+
+    private String toLog(final Request request) {
+        return request.getMethod() + request.getUri();
+    }
+}
diff --git a/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/LDAPCollectionResourceProvider.java b/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/LDAPCollectionResourceProvider.java
index e0ff373..1901eb4 100644
--- a/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/LDAPCollectionResourceProvider.java
+++ b/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/LDAPCollectionResourceProvider.java
@@ -15,6 +15,7 @@
  */
 package org.forgerock.opendj.rest2ldap;
 
+import static org.forgerock.i18n.LocalizableMessage.raw;
 import static org.forgerock.opendj.rest2ldap.Rest2ldapMessages.*;
 import static java.util.Arrays.asList;
 import static org.forgerock.opendj.ldap.Filter.alwaysFalse;
@@ -39,6 +40,8 @@
 import java.util.List;
 import java.util.Set;
 
+import org.forgerock.i18n.LocalizableMessage;
+import org.forgerock.i18n.slf4j.LocalizedLogger;
 import org.forgerock.json.JsonPointer;
 import org.forgerock.json.JsonValue;
 import org.forgerock.json.JsonValueException;
@@ -95,6 +98,7 @@
 import org.forgerock.services.context.Context;
 import org.forgerock.services.context.SecurityContext;
 import org.forgerock.util.AsyncFunction;
+
 import org.forgerock.util.Function;
 import org.forgerock.util.promise.ExceptionHandler;
 import org.forgerock.util.promise.Promise;
@@ -109,6 +113,9 @@
  * resource collection to LDAP entries beneath a base DN.
  */
 final class LDAPCollectionResourceProvider implements CollectionResourceProvider {
+
+    private static final LocalizedLogger logger = LocalizedLogger.getLoggerForThisClass();
+
     /** Dummy exception used for signalling search success. */
     private static final ResourceException SUCCESS = new UncategorizedException(0, null, null);
 
@@ -171,7 +178,9 @@
             oldPassword = jsonContent.get("oldPassword").asString();
             newPassword = jsonContent.get("newPassword").asString();
         } catch (JsonValueException e) {
-            final ResourceException ex = newBadRequestException(ERR_PASSWORD_MODIFY_REQUEST_IS_INVALID.get(), e);
+            final LocalizableMessage msg = ERR_PASSWORD_MODIFY_REQUEST_IS_INVALID.get();
+            final ResourceException ex = newBadRequestException(msg, e);
+            logger.error(msg, e);
             return Promises.newExceptionPromise(ex);
         }
 
@@ -233,6 +242,7 @@
                                     request.getNewResourceId(),
                                     addRequest);
                         } catch (final ResourceException e) {
+                            logger.error(raw(e.getLocalizedMessage()), e);
                             return Promises.newExceptionPromise(e);
                         }
                         if (config.readOnUpdatePolicy() == CONTROLS) {
@@ -669,7 +679,7 @@
                                         cookie = control.getCookie().toBase64String();
                                     }
                                 } catch (final DecodeException e) {
-                                    // FIXME: need some logging.
+                                    logger.error(ERR_DECODING_CONTROL.get(e.getLocalizedMessage()), e);
                                 }
                             }
                             completeIfNecessary(SUCCESS, promise);
@@ -930,7 +940,7 @@
                         }
                     }
                 } catch (final DecodeException e) {
-                    // FIXME: log something?
+                    logger.error(ERR_DECODING_CONTROL.get(e.getLocalizedMessage()), e);
                     entry = null;
                 }
                 if (entry != null) {
diff --git a/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/Rest2LDAPHttpApplication.java b/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/Rest2LDAPHttpApplication.java
index 3e312f7..20d984d 100644
--- a/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/Rest2LDAPHttpApplication.java
+++ b/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/Rest2LDAPHttpApplication.java
@@ -60,6 +60,8 @@
 import org.forgerock.http.handler.HttpClientHandler;
 import org.forgerock.http.io.Buffer;
 import org.forgerock.http.protocol.Headers;
+import org.forgerock.i18n.LocalizableMessage;
+import org.forgerock.i18n.slf4j.LocalizedLogger;
 import org.forgerock.json.JsonValue;
 import org.forgerock.json.resource.RequestHandler;
 import org.forgerock.json.resource.Router;
@@ -81,8 +83,6 @@
 import org.forgerock.util.promise.Promise;
 import org.forgerock.util.time.Duration;
 import org.forgerock.util.time.TimeService;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
 
 /** Rest2ldap HTTP application. */
 public class Rest2LDAPHttpApplication implements HttpApplication {
@@ -101,7 +101,7 @@
     private static final String CACHE_ENABLED = "enabled";
     private static final String CACHE_EXPIRATION = "cacheExpiration";
 
-    private static final Logger LOG = LoggerFactory.getLogger(Rest2LDAPHttpApplication.class);
+    private static final LocalizedLogger logger = LocalizedLogger.getLoggerForThisClass();
 
     /** URL to the JSON configuration file. */
     protected final URL configurationUrl;
@@ -178,12 +178,13 @@
             configureConnectionFactories(configuration.get("ldapConnectionFactories"));
             return Handlers.chainOf(
                     CrestHttp.newHttpHandler(configureRest2Ldap(configuration)),
+                    new ErrorLoggerFilter(),
                     buildAuthorizationFilter(configuration.get("authorization").required()));
         } catch (final Exception e) {
-            final String errorMsg = ERR_FAIL_PARSE_CONFIGURATION.get(e.getLocalizedMessage()).toString();
-            LOG.error(errorMsg, e);
+            final LocalizableMessage errorMsg = ERR_FAIL_PARSE_CONFIGURATION.get(e.getLocalizedMessage());
+            logger.error(errorMsg, e);
             stop();
-            throw new HttpApplicationException(errorMsg, e);
+            throw new HttpApplicationException(errorMsg.toString(), e);
         }
     }
 
diff --git a/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/authz/CachedReadConnectionDecorator.java b/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/authz/CachedReadConnectionDecorator.java
index d355612..0d72c5a 100644
--- a/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/authz/CachedReadConnectionDecorator.java
+++ b/opendj-rest2ldap/src/main/java/org/forgerock/opendj/rest2ldap/authz/CachedReadConnectionDecorator.java
@@ -37,9 +37,13 @@
 import org.forgerock.opendj.ldap.requests.SearchRequest;
 import org.forgerock.opendj.ldap.responses.BindResult;
 import org.forgerock.opendj.ldap.responses.ExtendedResult;
+import org.forgerock.opendj.ldap.responses.Response;
 import org.forgerock.opendj.ldap.responses.Result;
 import org.forgerock.opendj.ldap.responses.SearchResultEntry;
 import org.forgerock.opendj.ldap.responses.SearchResultReference;
+import org.forgerock.util.promise.ResultHandler;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 /**
  * Cache entries by intercepting the result of base search requests. Entries in cache are automatically evicted if their
@@ -48,6 +52,21 @@
  */
 final class CachedReadConnectionDecorator extends AbstractAsynchronousConnectionDecorator {
 
+    private static final Logger logger = LoggerFactory.getLogger(CachedReadConnectionDecorator.class);
+
+    private static final ResultHandler<Response> RESPONSE_LOGGER = new ResultHandler<Response>() {
+        @Override
+        public void handleResult(final Response response) {
+            traceLog(response);
+        }
+    };
+
+    private static void traceLog(final Object o) {
+        if (logger.isTraceEnabled()) {
+            logger.trace(o.toString());
+        }
+    }
+
     @SuppressWarnings("serial")
     private final Map<DN, CachedRead> cachedReads = new LinkedHashMap<DN, CachedRead>() {
         private static final int MAX_CACHED_ENTRIES = 32;
@@ -167,8 +186,9 @@
          * Simple brute force implementation in case the bind operation
          * modifies an entry: clear the cachedReads.
          */
+        traceLog(request);
         evictAll();
-        return delegate.bindAsync(request, intermediateResponseHandler);
+        return delegate.bindAsync(request, intermediateResponseHandler).thenOnResult(RESPONSE_LOGGER);
     }
 
     private void evictAll() {
@@ -184,15 +204,17 @@
          * Simple brute force implementation in case the extended
          * operation modifies an entry: clear the cachedReads.
          */
+        traceLog(request);
         evictAll();
-        return delegate.extendedRequestAsync(request, intermediateResponseHandler);
+        return delegate.extendedRequestAsync(request, intermediateResponseHandler).thenOnResult(RESPONSE_LOGGER);
     }
 
     @Override
     public LdapPromise<Result> modifyAsync(ModifyRequest request,
             IntermediateResponseHandler intermediateResponseHandler) {
+        traceLog(request);
         evict(request.getName());
-        return delegate.modifyAsync(request, intermediateResponseHandler);
+        return delegate.modifyAsync(request, intermediateResponseHandler).thenOnResult(RESPONSE_LOGGER);
     }
 
     private void evict(final DN name) {
@@ -204,18 +226,20 @@
     @Override
     public LdapPromise<Result> deleteAsync(DeleteRequest request,
             IntermediateResponseHandler intermediateResponseHandler) {
+        traceLog(request);
         // Simple brute force implementation: clear the cachedReads.
         if (request.containsControl(SubtreeDeleteRequestControl.OID)) {
             evictAll();
         } else {
             evict(request.getName());
         }
-        return delegate.deleteAsync(request, intermediateResponseHandler);
+        return delegate.deleteAsync(request, intermediateResponseHandler).thenOnResult(RESPONSE_LOGGER);
     }
 
     @Override
     public LdapPromise<Result> modifyDNAsync(ModifyDNRequest request,
             IntermediateResponseHandler intermediateResponseHandler) {
+        traceLog(request);
         // Simple brute force implementation: clear the cachedReads.
         evictAll();
         return delegate.modifyDNAsync(request, intermediateResponseHandler);
@@ -229,8 +253,10 @@
          * object), or if the search request passed in an intermediate
          * response handler.
          */
+        traceLog(request);
         if (!request.getScope().equals(SearchScope.BASE_OBJECT) || intermediateResponseHandler != null) {
-            return delegate.searchAsync(request, intermediateResponseHandler, entryHandler);
+            return delegate.searchAsync(request, intermediateResponseHandler, entryHandler)
+                           .thenOnResult(RESPONSE_LOGGER);
         }
 
         // This is a read request and a candidate for caching.
@@ -252,7 +278,7 @@
                     .searchAsync(request, intermediateResponseHandler, pendingCachedRead)
                     .thenOnResult(pendingCachedRead).thenOnException(pendingCachedRead);
             pendingCachedRead.setPromise(promise);
-            return promise;
+            return promise.thenOnResult(RESPONSE_LOGGER);
         }
     }
 }
diff --git a/opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HTTPConnectionHandler.java b/opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HTTPConnectionHandler.java
index 9c86800..8ecf939 100644
--- a/opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HTTPConnectionHandler.java
+++ b/opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HTTPConnectionHandler.java
@@ -58,6 +58,7 @@
 import org.forgerock.opendj.config.server.ConfigurationChangeListener;
 import org.forgerock.opendj.ldap.DN;
 import org.forgerock.opendj.ldap.ResultCode;
+import org.forgerock.opendj.rest2ldap.ErrorLoggerFilter;
 import org.forgerock.opendj.server.config.server.ConnectionHandlerCfg;
 import org.forgerock.opendj.server.config.server.HTTPConnectionHandlerCfg;
 import org.forgerock.services.context.Context;
@@ -909,7 +910,8 @@
     {
       return Handlers.chainOf(
           serverContext.getHTTPRouter(),
-          new HttpLogFilter(serverContext),
+          new HttpAccessLogFilter(serverContext),
+          new ErrorLoggerFilter(),
           new ExecuteInWorkerThreadFilter(),
           new AllowDenyFilter(currentConfig.getDeniedClient(), currentConfig.getAllowedClient()),
           new CommonAuditTransactionIdFilter(serverContext),
diff --git a/opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HttpLogFilter.java b/opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HttpAccessLogFilter.java
similarity index 63%
rename from opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HttpLogFilter.java
rename to opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HttpAccessLogFilter.java
index 9afc654..85f5d14 100644
--- a/opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HttpLogFilter.java
+++ b/opendj-server-legacy/src/main/java/org/opends/server/protocols/http/HttpAccessLogFilter.java
@@ -15,16 +15,11 @@
  */
 package org.opends.server.protocols.http;
 
-import static  org.opends.messages.ProtocolMessages.ERR_HTTP_ERROR_WHILE_PROCESSING_REQUEST;
-import static org.opends.server.util.StaticUtils.stackTraceToSingleLineString;
-
 import org.forgerock.http.Filter;
 import org.forgerock.http.Handler;
 import org.forgerock.http.protocol.Request;
 import org.forgerock.http.protocol.Response;
-import org.forgerock.i18n.slf4j.LocalizedLogger;
 import org.forgerock.services.context.Context;
-import org.forgerock.util.promise.ExceptionHandler;
 import org.forgerock.util.promise.NeverThrowsException;
 import org.forgerock.util.promise.Promise;
 import org.forgerock.util.promise.ResultHandler;
@@ -34,13 +29,11 @@
  * Creates and inject a {@link HttpLogContext} containing information that'll be logged once the request has been
  * processed.
  */
-final class HttpLogFilter implements Filter
+final class HttpAccessLogFilter implements Filter
 {
-  private static final LocalizedLogger logger = LocalizedLogger.getLoggerForThisClass();
-
   private final ServerContext serverContext;
 
-  HttpLogFilter(final ServerContext serverContext)
+  HttpAccessLogFilter(final ServerContext serverContext)
   {
     this.serverContext = serverContext;
   }
@@ -49,30 +42,13 @@
   public Promise<Response, NeverThrowsException> filter(Context context, final Request request, Handler next)
   {
     final HttpLogContext logContext = new HttpLogContext(context, serverContext, request);
-    return next.handle(logContext, request).thenOnResultOrException(new ResultHandler<Response>()
+    return next.handle(logContext, request).thenOnResult(new ResultHandler<Response>()
     {
       @Override
       public void handleResult(Response result)
       {
         logContext.log(result.getStatus().getCode());
-        if (result.getCause() != null)
-        {
-          logError(request, result.getCause());
-        }
-      }
-    }, new ExceptionHandler<Exception>()
-    {
-      @Override
-      public void handleException(Exception exception)
-      {
-        logError(request, exception);
       }
     });
   }
-
-  private static void logError(Request request, Exception exception)
-  {
-    logger.error(ERR_HTTP_ERROR_WHILE_PROCESSING_REQUEST
-        .get(request.getUri(), stackTraceToSingleLineString(exception)));
-  }
 }
diff --git a/pom.xml b/pom.xml
index f4d3b4e..d988dff 100644
--- a/pom.xml
+++ b/pom.xml
@@ -394,6 +394,7 @@
                             <disabledFile>**/THIRDPARTYREADME.txt</disabledFile>
                             <disabledFile>legal-notices/CDDLv1_0.txt</disabledFile>
                             <disabledFile>**/tests/unit-tests-testng/resource/config-changes.ldif</disabledFile>
+                            <disabledFile>opendj-rest2ldap-servlet/src/main/webapp/WEB-INF/classes/logging.properties</disabledFile>
                         </disabledFiles>
                     </configuration>
                 </plugin>

--
Gitblit v1.10.0