Feature/378 request logging

CHANGELOG.md

@@ -19,6 +19,7 @@ List of changes that are finished but not yet released in any final version.
  - [PR-371](https://github.com/Cognifide/knotx/pull/371) - Fixed debug logging of HTTP Repository Connector
  - [PR-372](https://github.com/Cognifide/knotx/pull/372) - Added cache for compiled Handlebars snippets
  - [PR-374](https://github.com/Cognifide/knotx/pull/374) - Enable keepAlive connection in http client options
+ - [PR-379](https://github.com/Cognifide/knotx/pull/379) - Added access logging capabilities to the Knotx HTTP Server
 
 ## Version 1.1.2
  - [PR-318](https://github.com/Cognifide/knotx/pull/318) - Knot.x returns exit code `30` in case of missing config

documentation/src/main/wiki/Server.md

@@ -159,6 +159,7 @@ Main server options available.
 | `csrf`                      | `KnotxCSRFConfiguration`            |                | Configuration of the CSRF tokens |
 | `defaultFlow`               | `KnotxFlowConfiguration`            | ✔       | Configuration of [[default Knot.X routing|KnotRouting]] |
 | `customFlow`                | `KnotxFlowConfiguration`            |                | Configuration of [[Gateway Mode|GatewayMode]] |
+| `accessLog`                 | `AccessLogConfiguration`            |                | Configuration of the KnotxServer access log |
 
 ### KnotxServerCustomHeader options
  Name  | Type  | Mandatory | Description  |
@@ -214,6 +215,15 @@ The `repositories`, `splitter` and `assembler` verticles are specific to the def
 | `address`      | `String`         | ✔       | Event bus address of the **Knot** verticle |
 | `onTransition` | `KnotRouteEntry` |        | Describes routing to addresses of other Knots based on the transition trigger returned from current Knot.<br/>`"onTransition": { "go-d": {}, "go-e": {} }` |
 
+
+### AccessLogConfiguration options
+| Name  | Type  | Mandatory | Description  |
+|-------:|:-------:|:-------:  |-------|
+| `enabled`   | `boolean` |       | Enable/Disable access log. Default is `true` |
+| `immediate` | `boolean` |       | Log before request or after. Default is `false` - log after request |
+| `format`    | `String` |        | Format of the access log. Allowed valueds are `DEFAULT`, `SHORT`, `TINY`. Default tries to log in a format similar to Apache log format, while the other 2 are more suited to development mode. Default format is `DEFAULT` |
+
+
 ### Vert.x HTTP Server configurations
 
 Besides Knot.x specific configurations as mentioned above, the `config` field might have added Vert.x configurations related to the HTTP server.
@@ -345,3 +355,50 @@ for eventubs requests that come from `KnotxServer`.
   }
 }
 ```
+
+### Configure access log
+Knot.x uses a default Logging handler from the Vert.x web distribution that allows to log all incomming requests to the Http server.
+It supports three log line formats that are:
+- DEFAULT that tries to log in a format similar to Apache log format
+`127.0.0.1 - - [Tue, 23 Jan 2018 14:16:34 GMT] "GET /content/local/simple.html HTTP/1.1" 200 2963 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.132 Safari/537.36"`
+- SHORT
+`127.0.0.1 - GET /content/local/simple.html HTTP/1.1 200 2963 - 19 ms`
+- TINY
+`GET /content/local/simple.html 200 2963 - 24 ms`
+
+By default access log is enabled with a `DEFAULT` format. If you want to change it, just add access logging section on the KnotxServer configuration in your application.json config file :
+```json
+{
+  "config": {
+    "knotx:io.knotx.KnotxServer": {
+      "options": {
+        "config": {
+          "accessLog": {
+            "format": "TINY"
+          }
+        }
+      }
+    }
+  }
+}
+```
+In order to log the access log to a separate file, just configure your logger in `logback.xml` file as follows
+```xml
+  <appender name="access" class="ch.qos.logback.core.FileAppender">
+    <file>access.log</file>
+    <append>true</append>
+    <!-- set immediateFlush to false for much higher logging throughput -->
+    <immediateFlush>true</immediateFlush>
+    <encoder>
+      <pattern>%msg%n</pattern>
+    </encoder>
+  </appender>
+
+  <logger name="io.vertx.ext.web.handler.impl.LoggerHandlerImpl" level="INFO" additivity="false">
+    <appender-ref ref="access"/>
+  </logger>
+```
+This configures log appender as file, with the pattern being just a message.
+Next step, is to add logger for `io.vertx.ext.web.handler.impl.LoggerHandlerImpl` to be flushed out into your new appender.
+
+See [logback.xml](https://github.com/Cognifide/knotx/blob/master/knotx-example/knotx-example-app/src/main/resources/logback.xml) from the example app as an example.

knotx-example/knotx-example-app/src/main/resources/logback.xml

@@ -38,6 +38,20 @@
     </encoder>
   </appender>
 
+  <appender name="access" class="ch.qos.logback.core.FileAppender">
+    <file>access.log</file>
+    <append>true</append>
+    <!-- set immediateFlush to false for much higher logging throughput -->
+    <immediateFlush>true</immediateFlush>
+    <encoder>
+      <pattern>%msg%n</pattern>
+    </encoder>
+  </appender>
+
+  <logger name="io.vertx.ext.web.handler.impl.LoggerHandlerImpl" level="INFO" additivity="false">
+    <appender-ref ref="access"/>
+  </logger>
+
   <logger name="io.netty.handler.logging" level="TRACE" additivity="false">
     <appender-ref ref="netty-wire"/>
   </logger>

knotx-server/src/main/java/io/knotx/server/KnotxRepositoryHandler.java

@@ -60,7 +60,8 @@ public void handle(RoutingContext context) {
     final KnotContext knotContext = context.get(KnotContext.KEY);
 
     if (repositoryEntry.isPresent()) {
-      proxies.computeIfAbsent( repositoryEntry.get().address(),adr -> RepositoryConnectorProxy.createProxyWithOptions(vertx, adr, configuration.getDeliveryOptions()))
+      proxies.computeIfAbsent(repositoryEntry.get().address(), adr -> RepositoryConnectorProxy
+          .createProxyWithOptions(vertx, adr, configuration.getDeliveryOptions()))
           .rxProcess(knotContext.getClientRequest())
           .doOnSuccess(this::traceMessage)
           .subscribe(
@@ -91,8 +92,12 @@ void handleRepositoryResponse(ClientResponse repoResponse, RoutingContext contex
 
   private void endResponse(ClientResponse repoResponse, RoutingContext context) {
     writeHeaders(context.response(), repoResponse.getHeaders());
-    context.response().setStatusCode(repoResponse.getStatusCode())
-        .end(Buffer.newInstance(repoResponse.getBody()));
+    context.response().setStatusCode(repoResponse.getStatusCode());
+    if (repoResponse.getBody() != null) {
+      context.response().end(Buffer.newInstance(repoResponse.getBody()));
+    } else {
+      context.response().end();
+    }
   }
 
   private boolean isSuccessResponse(ClientResponse repoResponse) {

knotx-server/src/main/java/io/knotx/server/KnotxServerVerticle.java

@@ -31,8 +31,7 @@
 import io.vertx.reactivex.ext.web.handler.CSRFHandler;
 import io.vertx.reactivex.ext.web.handler.CookieHandler;
 import io.vertx.reactivex.ext.web.handler.ErrorHandler;
-import java.io.IOException;
-import java.net.URISyntaxException;
+import io.vertx.reactivex.ext.web.handler.LoggerHandler;
 
 public class KnotxServerVerticle extends AbstractVerticle {
 
@@ -47,7 +46,7 @@ public void init(Vertx vertx, Context context) {
   }
 
   @Override
-  public void start(Future<Void> fut) throws IOException, URISyntaxException {
+  public void start(Future<Void> fut) {
     LOGGER.info("Starting <{}>", this.getClass().getSimpleName());
     KnotxCSRFConfig csrfConfig = configuration.getCsrfConfig();
     CSRFHandler csrfHandler = CSRFHandler.create(csrfConfig.getSecret())
@@ -58,6 +57,10 @@ public void start(Future<Void> fut) throws IOException, URISyntaxException {
         .setTimeout(csrfConfig.getTimeout());
 
     Router router = Router.router(vertx);
+    if (configuration.getAccessLogConfig().isEnabled()) {
+      router.route().handler(LoggerHandler.create(configuration.getAccessLogConfig().isImmediate(),
+          configuration.getAccessLogConfig().getFormat()));
+    }
     router.route().handler(KnotxHeaderHandler.create(configuration));
     router.route().handler(SupportedMethodsAndPathsHandler.create(configuration));
     router.route().handler(CookieHandler.create());

knotx-server/src/main/java/io/knotx/server/configuration/AccessLogConfig.java

@@ -0,0 +1,49 @@
+/*
+ * Copyright (C) 2016 Cognifide Limited
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package io.knotx.server.configuration;
+
+import io.vertx.core.json.JsonObject;
+import io.vertx.ext.web.handler.LoggerFormat;
+
+public class AccessLogConfig {
+
+  public static final boolean DEFAULT_ENABLED = true;
+  public static final boolean DEFAULT_LOGGER_IMMEDIATE = false;
+  public static final String DEFAULT_LOGGER_FORMAT = LoggerFormat.DEFAULT.toString();
+
+  private boolean enabled;
+  private boolean immediate;
+  private LoggerFormat format;
+
+  public AccessLogConfig(JsonObject config) {
+    enabled = config.getBoolean("enabled", DEFAULT_ENABLED);
+    immediate = config.getBoolean("immediate", DEFAULT_LOGGER_IMMEDIATE);
+    format = LoggerFormat
+        .valueOf(config.getString("format", DEFAULT_LOGGER_FORMAT).toUpperCase());
+  }
+
+  public boolean isEnabled() {
+    return enabled;
+  }
+
+  public boolean isImmediate() {
+    return immediate;
+  }
+
+  public LoggerFormat getFormat() {
+    return format;
+  }
+}

knotx-server/src/main/java/io/knotx/server/configuration/KnotxServerConfiguration.java

@@ -46,6 +46,8 @@ public class KnotxServerConfiguration {
 
   private KnotxCSRFConfig csrfConfig;
 
+  private AccessLogConfig accessLogConfig;
+
   public KnotxServerConfiguration(JsonObject config) {
     displayExceptionDetails = config.getBoolean("displayExceptionDetails", false);
 
@@ -67,6 +69,8 @@ public KnotxServerConfiguration(JsonObject config) {
             config.getJsonObject("deliveryOptions"))
             : new DeliveryOptions();
     csrfConfig = new KnotxCSRFConfig(config.getJsonObject("csrf", new JsonObject()));
+
+    accessLogConfig = new AccessLogConfig(config.getJsonObject("accessLog", new JsonObject()));
   }
 
   public boolean displayExceptionDetails() {
@@ -108,4 +112,8 @@ public KnotxCSRFConfig getCsrfConfig() {
   public Long getFileUploadLimit() {
     return fileUploadLimit;
   }
+
+  public AccessLogConfig getAccessLogConfig() {
+    return accessLogConfig;
+  }
 }

knotx-standalone/src/main/resources/logback.xml

@@ -26,8 +26,22 @@
     </encoder>
   </appender>
 
+  <appender name="access" class="ch.qos.logback.core.FileAppender">
+    <file>access.log</file>
+    <append>true</append>
+    <!-- set immediateFlush to false for much higher logging throughput -->
+    <immediateFlush>true</immediateFlush>
+    <encoder>
+      <pattern>%msg%n</pattern>
+    </encoder>
+  </appender>
+
+  <logger name="io.vertx.ext.web.handler.impl.LoggerHandlerImpl" level="INFO" additivity="false">
+    <appender-ref ref="access"/>
+  </logger>
+
   <logger name="io.knotx" level="INFO"
-          additivity="false">
+      additivity="false">
     <appender-ref ref="STDOUT"/>
   </logger>