Add Dynamic-Log-Level feature

- New package called com.sap.hcp.cf.logging.servlet.dynlog in project
  cf-java-logging-support-servlet contains the classes for dynamic logging.
- DynamicLogLevelProcessor is called in RequestLoggingFilter and adds log
  level to MDC (if available in request-header)
- Class DynamicLogLevelHelper in core-project provides the same mdc key for all
  classes of all subprojects that need to access the thread-specific
  log level threshold in the mdc.
- Log level is provided in header field via RSA signed JWT token
- The Public Key for JWT token verification has to be provided via
  environment variable to the application
- The HTTP header name for the JWT token can be changed via environment variable
- The new threshold for log levels is considered via TurboFilters when using
  Logback and via DynamicThresholdFilters when using log4j2
- A detailed description about how to use this feature can be found in
  DynamicLogLevels.md which is also referenced in the main README.md

Change-Id: I8eee88d4cba7374424e040290fe67c845b5db88e

Author: ChristophEichhorn

DynamicLogLevels.md

@@ -0,0 +1,84 @@
+# Dynamic Log Levels
+
+## Summary
+
+Dynamic Log Levels enable application developers to set a specific log level for
+just one thread executed by their application. This feature allows to understand
+misbehavior of a live-system in detail for a specific request, without flooding
+the system with an enormous number of DEBUG level log messages emitted during 
+the processing of all other requests. This approach has the advantage that no
+unnecessary log messages need to be processed that might lead to quota
+exceedance. To avoid abuse of this feature, the dynamic log level has to be 
+provided within an RSA-signed JWT token that also contains an expiry date.
+
+## App-Configuration
+
+This feature is easy to use and requires only little extra configuration of the
+application. Depending on the logging framework in use, few additions have to be
+made to the logback.xml or the log4j2.xml file as described below. Regardless of
+the framework, the public RSA key required to verify the JWT token's signature
+must be provided in the application's environment variables. Furthermore an
+individually chosen name for the HTTPS header field can also be specified here.
+
+### Environment Variables
+
+- `DYN_LOG_HEADER`: a specific header name for the log level token can be 
+  defined here. If not specified, the default value (SAP-LOG-LEVEL) is used.
+
+- `DYN_LOG_LEVEL_KEY`: a public key which can be used to verify the JWT 
+  tokens that contain the dynamic log level.
+
+### Logback Specific Configuration
+
+In the logback.xml file, a turbofilter has to be defined by adding the following
+line to the configuration element:
+
+```xml
+<turboFilter class="com.sap.hcp.cf.logback.filter.CustomLoggingTurboFilter" />
+```
+
+### Log4j2 Specific Configuration
+
+In the log4j2.xml file, add the following to the configuration element:
+
+```xml
+<DynamicThresholdFilter key="dynamic_log_level"
+    defaultThreshold="ERROR" onMatch="ACCEPT" onMismatch="DENY">
+    <KeyValuePair key="TRACE" value="TRACE" />
+    <KeyValuePair key="DEBUG" value="DEBUG" />
+    <KeyValuePair key="INFO" value="INFO" />
+    <KeyValuePair key="WARN" value="WARN" />
+    <KeyValuePair key="ERROR" value="ERROR" />
+</DynamicThresholdFilter>
+```
+
+## Usage
+
+### What should a valid token look like
+
+A valid JWT token should be signed with RS256. Its payload should contain the
+email of the issuer, the desired log-level, a timestamp for the time at which
+the token has been generated and a timestamp that represents the expiry date.
+The Java class [TokenCreator] can be used to create valid tokens.
+
+[TokenCreator]: ./cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/dynlog/TokenCreator.java
+
+#### Header
+
+```json
+{
+  "alg": "RS256",
+  "typ": "JWT"
+}
+```
+
+#### Payload
+
+```json
+{
+  "issuer": "[email protected]",
+  "level": "TRACE",
+  "iat": 1506016127,
+  "exp": 1506188927
+}
+```

README.md

@@ -143,6 +143,13 @@ Here are sort of the minimal configurations you'd need:
 </Configuration>
 ```
 
+## Dynamic Log Levels
+
+This library provides the possibility to change the log-level threshold for a
+single thread by adding a token in the header of a request. A detailed
+description about how to apply this feature can be found
+[here](./DynamicLogLevels.md).
+
 ## Sample Application
 
 In order to illustrate how the different features are used, this repository includes a simple application in the  [./sample folder](./sample).

cf-java-logging-support-core/src/main/java/com/sap/hcp/cf/logging/common/helper/DynamicLogLevelHelper.java

@@ -0,0 +1,11 @@
+package com.sap.hcp.cf.logging.common.helper;
+
+public class DynamicLogLevelHelper {
+
+    /**
+     * This is the mdc key used to set and retrieve the dynamic log level to and
+     * from mdc
+     */
+    public static final String MDC_DYNAMIC_LOG_LEVEL_KEY = "dynamic_log_level";
+
+}

cf-java-logging-support-logback/src/main/java/com/sap/hcp/cf/logback/filter/CustomLoggingTurboFilter.java

@@ -0,0 +1,26 @@
+package com.sap.hcp.cf.logback.filter;
+
+import org.slf4j.MDC;
+import org.slf4j.Marker;
+
+import com.sap.hcp.cf.logging.common.helper.DynamicLogLevelHelper;
+
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.turbo.TurboFilter;
+import ch.qos.logback.core.spi.FilterReply;
+
+public class CustomLoggingTurboFilter extends TurboFilter {
+
+    @Override
+    public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) {
+        String logLevel = MDC.get(DynamicLogLevelHelper.MDC_DYNAMIC_LOG_LEVEL_KEY);
+        if (logLevel == null) {
+            return FilterReply.NEUTRAL;
+        }
+        if (level.isGreaterOrEqual(Level.toLevel(logLevel))) {
+            return FilterReply.ACCEPT;
+        }
+        return FilterReply.DENY;
+    }
+}

cf-java-logging-support-logback/src/test/java/com/sap/hcp/cf/logback/filter/CustomLoggingTurboFilterTest.java

@@ -0,0 +1,82 @@
+package com.sap.hcp.cf.logback.filter;
+
+import static org.junit.Assert.assertEquals;
+import static org.mockito.Mockito.verifyZeroInteractions;
+
+import org.junit.After;
+import org.junit.Before;
+import org.junit.Test;
+import org.junit.runner.RunWith;
+import org.mockito.Mock;
+import org.mockito.runners.MockitoJUnitRunner;
+import org.slf4j.MDC;
+import org.slf4j.Marker;
+
+import com.sap.hcp.cf.logging.common.helper.DynamicLogLevelHelper;
+
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.core.spi.FilterReply;
+
+@RunWith(MockitoJUnitRunner.class)
+public class CustomLoggingTurboFilterTest {
+
+    private CustomLoggingTurboFilter filter;
+
+    @Mock
+    private Marker marker;
+    private Logger logger;
+    private String format;
+    @Mock
+    private Object param;
+    private Object[] params;
+    @Mock
+    private Throwable t;
+
+    @Before
+    public void setup() {
+        filter = new CustomLoggingTurboFilter();
+        params = new Object[] { param };
+        format = "format";
+    }
+
+    @After
+    public void teardown() {
+        verifyZeroInteractions(marker, param, t);
+        MDC.clear();
+    }
+
+    @Test
+    public void testNeutralCondition() {
+        assertEquals(FilterReply.NEUTRAL, filter.decide(marker, logger, Level.TRACE, format, params, t));
+        assertEquals(FilterReply.NEUTRAL, filter.decide(marker, logger, Level.DEBUG, format, params, t));
+        assertEquals(FilterReply.NEUTRAL, filter.decide(marker, logger, Level.INFO, format, params, t));
+        assertEquals(FilterReply.NEUTRAL, filter.decide(marker, logger, Level.WARN, format, params, t));
+        assertEquals(FilterReply.NEUTRAL, filter.decide(marker, logger, Level.ERROR, format, params, t));
+    }
+
+    @Test
+    public void testAcceptCondition() {
+        assertEquals(FilterReply.NEUTRAL, filter.decide(marker, logger, Level.ERROR, format, params, t));
+
+        MDC.put(DynamicLogLevelHelper.MDC_DYNAMIC_LOG_LEVEL_KEY, "TRACE");
+
+        assertEquals(FilterReply.ACCEPT, filter.decide(marker, logger, Level.TRACE, format, params, t));
+        assertEquals(FilterReply.ACCEPT, filter.decide(marker, logger, Level.DEBUG, format, params, t));
+        assertEquals(FilterReply.ACCEPT, filter.decide(marker, logger, Level.INFO, format, params, t));
+        assertEquals(FilterReply.ACCEPT, filter.decide(marker, logger, Level.WARN, format, params, t));
+        assertEquals(FilterReply.ACCEPT, filter.decide(marker, logger, Level.ERROR, format, params, t));
+    }
+
+    @Test
+    public void testDenyCondition() {
+        assertEquals(FilterReply.NEUTRAL, filter.decide(marker, logger, Level.DEBUG, format, params, t));
+
+        MDC.put(DynamicLogLevelHelper.MDC_DYNAMIC_LOG_LEVEL_KEY, "INFO");
+        assertEquals(FilterReply.DENY, filter.decide(marker, logger, Level.TRACE, format, params, t));
+        assertEquals(FilterReply.DENY, filter.decide(marker, logger, Level.DEBUG, format, params, t));
+        assertEquals(FilterReply.ACCEPT, filter.decide(marker, logger, Level.INFO, format, params, t));
+        assertEquals(FilterReply.ACCEPT, filter.decide(marker, logger, Level.WARN, format, params, t));
+        assertEquals(FilterReply.ACCEPT, filter.decide(marker, logger, Level.ERROR, format, params, t));
+    }
+}

cf-java-logging-support-servlet/pom.xml

@@ -43,5 +43,11 @@
             <version>${logback.version}</version>
             <scope>test</scope>
         </dependency>
+        <!-- Library for token signing/verification -->
+        <dependency>
+            <groupId>com.auth0</groupId>
+            <artifactId>java-jwt</artifactId>
+            <version>3.2.0</version>
+        </dependency>
     </dependencies>
 </project>

cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/dynlog/DynLogEnvironment.java

@@ -0,0 +1,54 @@
+package com.sap.hcp.cf.logging.servlet.dynlog;
+
+import java.io.IOException;
+import java.security.NoSuchAlgorithmException;
+import java.security.interfaces.RSAPublicKey;
+import java.security.spec.InvalidKeySpecException;
+
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+public class DynLogEnvironment {
+
+    private static final Logger LOGGER = LoggerFactory.getLogger(DynLogEnvironment.class);
+    private final RSAPublicKey rsaPublicKey;
+    private final String dynLogHeaderKey;
+
+    public DynLogEnvironment() {
+        this(new Environment());
+    }
+
+    DynLogEnvironment(Environment environment) {
+        String header = environment.getVariable("DYN_LOG_HEADER");
+        if (header != null) {
+            dynLogHeaderKey = header;
+            LOGGER.info("The header key used to retrieve the dynamic log level token has been set to {}", header);
+        } else {
+            dynLogHeaderKey = "SAP-LOG-LEVEL";
+            LOGGER.info("The header key used to retrieve the dynamic log level token has been set to the default value: {}",
+                        dynLogHeaderKey);
+        }
+        PublicKeyReader publicKeyReader = new PublicKeyReader();
+
+        RSAPublicKey tempKey = null;
+        try {
+            tempKey = publicKeyReader.readPublicKey(environment);
+        } catch (NoSuchAlgorithmException e) {
+            LOGGER.error("Could not read RSAPublicKey from environment", e);
+        } catch (InvalidKeySpecException e) {
+            LOGGER.error("Could not read RSAPublicKey from environment", e);
+        } catch (IOException e) {
+            LOGGER.error("Could not read RSAPublicKey from environment", e);
+        } finally {
+            rsaPublicKey = tempKey;
+        }
+    }
+
+    public RSAPublicKey getRsaPublicKey() {
+        return rsaPublicKey;
+    }
+
+    public String getDynLogHeaderKey() {
+        return dynLogHeaderKey;
+    }
+}

cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/dynlog/DynamicLogLevelException.java

@@ -0,0 +1,19 @@
+package com.sap.hcp.cf.logging.servlet.dynlog;
+
+import javax.servlet.ServletException;
+
+import com.auth0.jwt.exceptions.JWTVerificationException;
+
+public class DynamicLogLevelException extends ServletException {
+
+    private static final long serialVersionUID = 1L;
+
+    public DynamicLogLevelException(String message, JWTVerificationException cause) {
+        super(message, cause);
+    }
+
+    public DynamicLogLevelException(String message) {
+        super(message);
+    }
+
+}

cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/dynlog/DynamicLogLevelProcessor.java

@@ -0,0 +1,54 @@
+package com.sap.hcp.cf.logging.servlet.dynlog;
+
+import java.util.Arrays;
+import java.util.List;
+
+import javax.servlet.http.HttpServletRequest;
+
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.MDC;
+
+import com.auth0.jwt.interfaces.DecodedJWT;
+import com.sap.hcp.cf.logging.common.helper.DynamicLogLevelHelper;
+
+/**
+ * This class provides a mechanism that reads a token from an
+ * HTTP-request-header. If this token is provided and does contain a correct
+ * signature, valid timestamps and a log-level-value, the log-level for the
+ * thread triggered by this request will be changed to the provided value.
+ */
+public class DynamicLogLevelProcessor {
+
+    private final static Logger LOGGER = LoggerFactory.getLogger(DynamicLogLevelProcessor.class);
+    private static final List<String> ALLOWED_DYNAMIC_LOGLEVELS = Arrays.asList("TRACE", "DEBUG", "INFO", "WARN",
+                                                                                "ERROR");
+    private final TokenDecoder tokenDecoder;
+    private final DynLogEnvironment dynLogEnvironment;
+
+    public DynamicLogLevelProcessor(DynLogEnvironment dynLogEnvironment) {
+        this.dynLogEnvironment = dynLogEnvironment;
+        this.tokenDecoder = new TokenDecoder(dynLogEnvironment.getRsaPublicKey());
+    }
+
+    public void copyDynamicLogLevelToMDC(HttpServletRequest httpRequest) {
+        String logLevelToken = httpRequest.getHeader(dynLogEnvironment.getDynLogHeaderKey());
+        if (logLevelToken == null) {
+            return;
+        } else {
+            try {
+                DecodedJWT jwt = tokenDecoder.validateAndDecodeToken(logLevelToken);
+                String dynamicLogLevel = jwt.getClaim("level").asString();
+                if (ALLOWED_DYNAMIC_LOGLEVELS.contains(dynamicLogLevel)) {
+                    MDC.put(DynamicLogLevelHelper.MDC_DYNAMIC_LOG_LEVEL_KEY, dynamicLogLevel);
+                } else {
+                    throw new DynamicLogLevelException("Dynamic Log-Level [" + dynamicLogLevel +
+                                                       "] provided in header is not valid. Allowed Values are " +
+                                                       ALLOWED_DYNAMIC_LOGLEVELS.toString());
+                }
+            } catch (DynamicLogLevelException e) {
+                LOGGER.error("DynamicLogLevelProcessor could not write dynamic log level to MDC", e);
+            }
+        }
+    }
+}

cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/dynlog/Environment.java

@@ -0,0 +1,8 @@
+package com.sap.hcp.cf.logging.servlet.dynlog;
+
+public class Environment {
+
+    public String getVariable(String name) {
+        return System.getenv(name);
+    }
+}