Access log refactoring

core/src/main/java/com/predic8/membrane/core/interceptor/log/AccessLogInterceptor.java

@@ -22,7 +22,8 @@
 import com.predic8.membrane.core.interceptor.AbstractInterceptor;
 import com.predic8.membrane.core.interceptor.Outcome;
 
-import java.util.*;
+import java.util.ArrayList;
+import java.util.List;
 
 import static com.predic8.membrane.core.interceptor.Outcome.CONTINUE;
 
@@ -57,6 +58,11 @@ public Outcome handleResponse(Exchange exc) throws Exception {
         return CONTINUE;
     }
 
+    @Override
+    public void handleAbort(Exchange exc) {
+        accessLogInterceptorService.handleAccessLogging(exc);
+    }
+
     @SuppressWarnings("unused")
     public List<AdditionalVariable> getAdditionalPatternList() {
         return additionalVariables;

core/src/main/java/com/predic8/membrane/core/interceptor/log/AccessLogInterceptorService.java

@@ -16,12 +16,11 @@
 package com.predic8.membrane.core.interceptor.log;
 
 import com.predic8.membrane.core.exchange.Exchange;
-import com.predic8.membrane.core.http.*;
+import com.predic8.membrane.core.http.Message;
 import com.predic8.membrane.core.lang.spel.ExchangeEvaluationContext;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 import org.slf4j.MDC;
-import org.springframework.expression.spel.standard.SpelExpressionParser;
 
 import java.io.IOException;
 import java.text.SimpleDateFormat;
@@ -154,9 +153,7 @@ private Map<String, String> getAdditionalProvidedPattern(Exchange exc) {
     private Function<AdditionalVariable, AbstractMap.SimpleEntry<String, String>> additionalPatternToMapEntry(Exchange exc) {
         return additionalPattern -> new AbstractMap.SimpleEntry<>(
                 additionalPattern.getName(),
-                safe(() -> new SpelExpressionParser()
-                        .parseExpression(additionalPattern.getExpression())
-                        .getValue(new ExchangeEvaluationContext(exc)),
+                safe(() ->  additionalPattern.getExpression().getValue(new ExchangeEvaluationContext(exc)),
                     additionalPattern.getDefaultValue()
                 )
         );

core/src/main/java/com/predic8/membrane/core/interceptor/log/AdditionalVariable.java

@@ -18,15 +18,17 @@
 import com.predic8.membrane.annot.MCAttribute;
 import com.predic8.membrane.annot.MCElement;
 import com.predic8.membrane.annot.Required;
+import org.springframework.expression.Expression;
+import org.springframework.expression.spel.standard.SpelExpressionParser;
 
 @MCElement(name = "additionalVariable", topLevel = false, id = "accessLog-scope")
 public class AdditionalVariable {
 
     private String name;
-    private String expression;
+    private Expression expression;
     private String defaultValue = "-";
 
-    public String getExpression() {
+    public Expression getExpression() {
         return expression;
     }
 
@@ -37,7 +39,8 @@ public String getExpression() {
     @Required
     @MCAttribute
     public void setExpression(String expression) {
-        this.expression = expression;
+        this.expression = new SpelExpressionParser()
+                .parseExpression(expression);
     }
 
     public String getName() {

distribution/examples/logging/access/log4j2_access.xml

@@ -5,10 +5,10 @@
             <PatternLayout pattern="%d{ABSOLUTE} %5p %c{1}:%L - %m%n" />
         </Console>
         <Console name="ACCESS" target="SYSTEM_OUT">
-            <PatternLayout pattern="%X{ip} [%X{time.req.received.format}]  &quot;%X{http.method} %X{uri} %X{proto}/%X{http.version}&quot; %X{statusCode} %X{req.payload.size} [%X{res.contentType}]%n" />
+            <PatternLayout pattern="%X{ip} [%X{time.req.received.format}] X-Forwarded-For: %X{forwarded} &quot;%X{http.method} %X{uri} %X{proto}/%X{http.version}&quot; %X{statusCode} %X{req.payload.size} [%X{res.contentType}]%n" />
         </Console>
         <RollingFile name="ACCESS_FILE" fileName="access.log" filePattern="access.log.%i">
-            <PatternLayout pattern="%X{ip} [%X{time.req.received.format}] &quot;%X{http.method} %X{uri} %X{proto}/%X{http.version}&quot; %X{statusCode} %X{req.payload.size} [%X{res.contentType}]%n" />
+            <PatternLayout pattern="%X{ip} [%X{time.req.received.format}] X-Forwarded-For: %X{forwarded} &quot;%X{http.method} %X{uri} %X{proto}/%X{http.version}&quot; %X{statusCode} %X{req.payload.size} [%X{res.contentType}]%n" />
             <Policies>
                 <SizeBasedTriggeringPolicy size="100 MB" />
             </Policies>

distribution/examples/logging/access/proxies.xml

@@ -9,6 +9,7 @@
         <api port="2000">
             <accessLog>
                 <additionalVariable name="res.contentType" expression="response?.headers.contentType" />
+                <additionalVariable name="forwarded" expression="headers['x-forwarded-for']" />
             </accessLog>
             <target host="api.predic8.de">
                 <ssl />

distribution/src/test/java/com/predic8/membrane/examples/ExampleTestsWithoutInternet.java

@@ -23,6 +23,7 @@
 import com.predic8.membrane.examples.tests.loadbalancing.Loadbalancing1StaticTest;
 import com.predic8.membrane.examples.tests.loadbalancing.Loadbalancing3ClientTest;
 import com.predic8.membrane.examples.tests.loadbalancing.Loadbalancing5MultipleTest;
+import com.predic8.membrane.examples.tests.log.AccessLogTest;
 import com.predic8.membrane.examples.tests.message_transformation.Json2XmlTest;
 import com.predic8.membrane.examples.tests.message_transformation.TransformationUsingJavascriptTest;
 import com.predic8.membrane.examples.tests.message_transformation.Xml2JsonTest;
@@ -66,6 +67,9 @@
         XMLValidationTest.class,
         SampleSoapServiceTest.class,
 
+        // Logging
+        AccessLogTest.class,
+
         // Transformation
         Xml2JsonTest.class,
         Json2XmlTest.class,

distribution/src/test/java/com/predic8/membrane/examples/tests/log/AccessLogTest.java

@@ -20,8 +20,8 @@
 import org.junit.jupiter.api.Test;
 
 import static com.predic8.membrane.test.AssertUtils.assertContains;
-import static org.junit.jupiter.api.Assertions.*;
 import static com.predic8.membrane.test.AssertUtils.getAndAssert200;
+import static org.junit.jupiter.api.Assertions.assertTrue;
 
 public class AccessLogTest extends DistributionExtractingTestcase {
 
@@ -33,7 +33,7 @@ protected String getExampleDirName() {
     @Test
     void testConsole() throws Exception {
         try (var process = startServiceProxyScript()) {
-            var console = new WaitableConsoleEvent(process, p -> p.equals("127.0.0.1 \"GET / HTTP/1.1\" 200 0 [application/json]"));
+            var console = new WaitableConsoleEvent(process, p -> p.contains("\"GET / HTTP/1.1\" 200 0 [application/json]"));
             getAndAssert200("http://localhost:2000");
             assertTrue(console.occurred());
         }
@@ -44,6 +44,14 @@ void testRollingFile() throws Exception {
         try (var ignore = startServiceProxyScript()) {
             getAndAssert200("http://localhost:2000");
         }
-        assertContains("127.0.0.1 \"GET / HTTP/1.1\" 200 0 [application/json]", readFile("access.log"));
+        assertContains("\"GET / HTTP/1.1\" 200 0 [application/json]", readFile("access.log"));
+    }
+
+    @Test
+    void testHeader() throws Exception {
+        try (var ignore = startServiceProxyScript()) {
+            getAndAssert200("http://localhost:2000");
+        }
+        assertContains("X-Forwarded-For: 127.0.0.1", readFile("access.log"));
     }
 }