Add option to log all requests and responses.

docs/configure.md

@@ -82,8 +82,9 @@ See [the migration instruction](migration-to-postgresql.md) from sqlite to postg
 ## Logging
 ```yaml
 logging:
-  root: error  # default level for all loggers (apps and thirdparty libraries)
-  app: info    # log level only for the ma1sd
+  root: error     # default level for all loggers (apps and thirdparty libraries)
+  app: info       # log level only for the ma1sd
+  requests: false # log request and response
 ```
 
 Possible value: `trace`, `debug`, `info`, `warn`, `error`, `off`.
@@ -100,6 +101,11 @@ Default value for app level: `info`.
 | -v | app: debug |
 | -vv | app: trace |
 
+#### WARNING
+
+The setting `logging.requests` *MUST NOT* be used in production due it prints full unmasked request and response into the log and can be cause of the data leak. 
+This setting can be used only to testing and debugging errors.
+
 ## Identity stores
 See the [Identity stores](stores/README.md) for specific configuration
 

ma1sd.example.yaml

@@ -199,4 +199,6 @@ threepid:
 #
 
 # logging:
-#   root: trace   # logging level
+#   root: error     # default level for all loggers (apps and thirdparty libraries)
+#   app: info       # log level only for the ma1sd
+#   requests: false # or true to dump full requests and responses

src/main/java/io/kamax/mxisd/HttpMxisd.java

@@ -29,6 +29,7 @@ import io.kamax.mxisd.http.undertow.handler.AuthorizationHandler;
 import io.kamax.mxisd.http.undertow.handler.CheckTermsHandler;
 import io.kamax.mxisd.http.undertow.handler.InternalInfoHandler;
 import io.kamax.mxisd.http.undertow.handler.OptionsHandler;
+import io.kamax.mxisd.http.undertow.handler.RequestDumpingHandler;
 import io.kamax.mxisd.http.undertow.handler.SaneHandler;
 import io.kamax.mxisd.http.undertow.handler.as.v1.AsNotFoundHandler;
 import io.kamax.mxisd.http.undertow.handler.as.v1.AsTransactionHandler;
@@ -100,9 +101,9 @@ public class HttpMxisd {
     public void start() {
         m.start();
 
-        HttpHandler asUserHandler = SaneHandler.around(new AsUserHandler(m.getAs()));
-        HttpHandler asTxnHandler = SaneHandler.around(new AsTransactionHandler(m.getAs()));
-        HttpHandler asNotFoundHandler = SaneHandler.around(new AsNotFoundHandler(m.getAs()));
+        HttpHandler asUserHandler = sane(new AsUserHandler(m.getAs()));
+        HttpHandler asTxnHandler = sane(new AsTransactionHandler(m.getAs()));
+        HttpHandler asNotFoundHandler = sane(new AsNotFoundHandler(m.getAs()));
 
         final RoutingHandler handler = Handlers.routing()
             .add("OPTIONS", "/**", sane(new OptionsHandler()))
@@ -267,6 +268,11 @@ public class HttpMxisd {
     }
 
     private HttpHandler sane(HttpHandler httpHandler) {
-        return SaneHandler.around(httpHandler);
+        SaneHandler handler = SaneHandler.around(httpHandler);
+        if (m.getConfig().getLogging().isRequests()) {
+            return new RequestDumpingHandler(handler);
+        } else {
+            return handler;
+        }
     }
 }

src/main/java/io/kamax/mxisd/config/LoggingConfig.java

@@ -10,6 +10,7 @@ public class LoggingConfig {
 
     private String root;
     private String app;
+    private boolean requests = false;
 
     public String getRoot() {
         return root;
@@ -27,6 +28,14 @@ public class LoggingConfig {
         this.app = app;
     }
 
+    public boolean isRequests() {
+        return requests;
+    }
+
+    public void setRequests(boolean requests) {
+        this.requests = requests;
+    }
+
     public void build() {
         LOGGER.info("Logging config:");
         if (StringUtils.isNotBlank(getRoot())) {
@@ -43,5 +52,9 @@ public class LoggingConfig {
         } else {
             LOGGER.info("  Logging level hasn't set, use default");
         }
+        LOGGER.info("  Log requests: {}", isRequests());
+        if (isRequests()) {
+            LOGGER.warn("  Request dumping enabled, use this only to debug purposes, don't use it in the production.");
+        }
     }
 }

src/main/java/io/kamax/mxisd/http/undertow/conduit/ConduitWithDump.java

@@ -0,0 +1,5 @@
+package io.kamax.mxisd.http.undertow.conduit;
+
+public interface ConduitWithDump {
+    String dump();
+}

src/main/java/io/kamax/mxisd/http/undertow/conduit/DebuggingStreamSinkConduit.java

@@ -0,0 +1,107 @@
+/*
+ * JBoss, Home of Professional Open Source.
+ * Copyright 2014 Red Hat, Inc., and individual contributors
+ * as indicated by the @author tags.
+ *
+ * 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.kamax.mxisd.http.undertow.conduit;
+
+import org.xnio.IoUtils;
+import org.xnio.channels.StreamSourceChannel;
+import org.xnio.conduits.AbstractStreamSinkConduit;
+import org.xnio.conduits.ConduitWritableByteChannel;
+import org.xnio.conduits.Conduits;
+import org.xnio.conduits.StreamSinkConduit;
+
+import java.io.IOException;
+import java.nio.ByteBuffer;
+import java.nio.channels.FileChannel;
+import java.nio.charset.StandardCharsets;
+import java.util.List;
+import java.util.concurrent.CopyOnWriteArrayList;
+
+/**
+ * Conduit that saves all the data that is written through it and can dump it to the console
+ * <p>
+ * Obviously this should not be used in production.
+ *
+ * @author Stuart Douglas
+ */
+public class DebuggingStreamSinkConduit extends AbstractStreamSinkConduit<StreamSinkConduit> implements ConduitWithDump {
+
+    private final List<byte[]> data = new CopyOnWriteArrayList<>();
+
+    /**
+     * Construct a new instance.
+     *
+     * @param next the delegate conduit to set
+     */
+    public DebuggingStreamSinkConduit(StreamSinkConduit next) {
+        super(next);
+    }
+
+    @Override
+    public int write(ByteBuffer src) throws IOException {
+        int pos = src.position();
+        int res = super.write(src);
+        if (res > 0) {
+            byte[] d = new byte[res];
+            for (int i = 0; i < res; ++i) {
+                d[i] = src.get(i + pos);
+            }
+            data.add(d);
+        }
+        return res;
+    }
+
+    @Override
+    public long write(ByteBuffer[] dsts, int offs, int len) throws IOException {
+        for (int i = offs; i < len; ++i) {
+            if (dsts[i].hasRemaining()) {
+                return write(dsts[i]);
+            }
+        }
+        return 0;
+    }
+
+    @Override
+    public long transferFrom(final FileChannel src, final long position, final long count) throws IOException {
+        return src.transferTo(position, count, new ConduitWritableByteChannel(this));
+    }
+
+    @Override
+    public long transferFrom(final StreamSourceChannel source, final long count, final ByteBuffer throughBuffer) throws IOException {
+        return IoUtils.transfer(source, count, throughBuffer, new ConduitWritableByteChannel(this));
+    }
+
+    @Override
+    public int writeFinal(ByteBuffer src) throws IOException {
+        return Conduits.writeFinalBasic(this, src);
+    }
+
+    @Override
+    public long writeFinal(ByteBuffer[] srcs, int offset, int length) throws IOException {
+        return Conduits.writeFinalBasic(this, srcs, offset, length);
+    }
+
+    @Override
+    public String dump() {
+        StringBuilder sb = new StringBuilder();
+        for (byte[] datum : data) {
+            sb.append(new String(datum, StandardCharsets.UTF_8));
+        }
+        return sb.toString();
+    }
+}

src/main/java/io/kamax/mxisd/http/undertow/conduit/DebuggingStreamSourceConduit.java

@@ -0,0 +1,95 @@
+/*
+ * JBoss, Home of Professional Open Source.
+ * Copyright 2014 Red Hat, Inc., and individual contributors
+ * as indicated by the @author tags.
+ *
+ * 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.kamax.mxisd.http.undertow.conduit;
+
+import org.xnio.IoUtils;
+import org.xnio.channels.StreamSinkChannel;
+import org.xnio.conduits.AbstractStreamSourceConduit;
+import org.xnio.conduits.ConduitReadableByteChannel;
+import org.xnio.conduits.StreamSourceConduit;
+
+import java.io.IOException;
+import java.nio.ByteBuffer;
+import java.nio.channels.FileChannel;
+import java.nio.charset.StandardCharsets;
+import java.util.List;
+import java.util.concurrent.CopyOnWriteArrayList;
+
+/**
+ * Conduit that saves all the data that is written through it and can dump it to the console
+ * <p>
+ * Obviously this should not be used in production.
+ *
+ * @author Stuart Douglas
+ */
+public class DebuggingStreamSourceConduit extends AbstractStreamSourceConduit<StreamSourceConduit> implements ConduitWithDump {
+
+    private final List<byte[]> data = new CopyOnWriteArrayList<>();
+
+    /**
+     * Construct a new instance.
+     *
+     * @param next the delegate conduit to set
+     */
+    public DebuggingStreamSourceConduit(StreamSourceConduit next) {
+        super(next);
+    }
+
+    public long transferTo(final long position, final long count, final FileChannel target) throws IOException {
+        return target.transferFrom(new ConduitReadableByteChannel(this), position, count);
+    }
+
+    public long transferTo(final long count, final ByteBuffer throughBuffer, final StreamSinkChannel target) throws IOException {
+        return IoUtils.transfer(new ConduitReadableByteChannel(this), count, throughBuffer, target);
+    }
+
+    @Override
+    public int read(ByteBuffer dst) throws IOException {
+        int pos = dst.position();
+        int res = super.read(dst);
+        if (res > 0) {
+            byte[] d = new byte[res];
+            for (int i = 0; i < res; ++i) {
+                d[i] = dst.get(i + pos);
+            }
+            data.add(d);
+        }
+        return res;
+    }
+
+    @Override
+    public long read(ByteBuffer[] dsts, int offs, int len) throws IOException {
+        for (int i = offs; i < len; ++i) {
+            if (dsts[i].hasRemaining()) {
+                return read(dsts[i]);
+            }
+        }
+        return 0;
+    }
+
+    @Override
+    public String dump() {
+
+        StringBuilder sb = new StringBuilder();
+        for (byte[] datum : data) {
+            sb.append(new String(datum, StandardCharsets.UTF_8));
+        }
+        return sb.toString();
+    }
+}

src/main/java/io/kamax/mxisd/http/undertow/conduit/LazyConduitWrapper.java

@@ -0,0 +1,23 @@
+package io.kamax.mxisd.http.undertow.conduit;
+
+import io.undertow.server.ConduitWrapper;
+import io.undertow.server.HttpServerExchange;
+import io.undertow.util.ConduitFactory;
+import org.xnio.conduits.Conduit;
+
+public abstract class LazyConduitWrapper<T extends Conduit> implements ConduitWrapper<T> {
+
+    private T conduit = null;
+
+    protected abstract T create(ConduitFactory<T> factory, HttpServerExchange exchange);
+
+    @Override
+    public T wrap(ConduitFactory<T> factory, HttpServerExchange exchange) {
+        conduit = create(factory, exchange);
+        return conduit;
+    }
+
+    public T get() {
+        return conduit;
+    }
+}

src/main/java/io/kamax/mxisd/http/undertow/handler/RequestDumpingHandler.java

@@ -0,0 +1,186 @@
+/*
+ * JBoss, Home of Professional Open Source.
+ * Copyright 2014 Red Hat, Inc., and individual contributors
+ * as indicated by the @author tags.
+ *
+ * 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.kamax.mxisd.http.undertow.handler;
+
+import io.kamax.mxisd.http.undertow.conduit.ConduitWithDump;
+import io.kamax.mxisd.http.undertow.conduit.DebuggingStreamSinkConduit;
+import io.kamax.mxisd.http.undertow.conduit.DebuggingStreamSourceConduit;
+import io.kamax.mxisd.http.undertow.conduit.LazyConduitWrapper;
+import io.undertow.security.api.SecurityContext;
+import io.undertow.server.HttpHandler;
+import io.undertow.server.HttpServerExchange;
+import io.undertow.server.handlers.Cookie;
+import io.undertow.util.ConduitFactory;
+import io.undertow.util.HeaderValues;
+import io.undertow.util.Headers;
+import io.undertow.util.LocaleUtils;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.xnio.conduits.StreamSinkConduit;
+import org.xnio.conduits.StreamSourceConduit;
+
+import java.util.Deque;
+import java.util.Iterator;
+import java.util.Map;
+
+/**
+ * Handler that dumps a exchange to a log.
+ *
+ * @author Stuart Douglas
+ */
+public class RequestDumpingHandler implements HttpHandler {
+
+    private static final Logger LOGGER = LoggerFactory.getLogger(RequestDumpingHandler.class);
+
+    private final HttpHandler next;
+
+    public RequestDumpingHandler(HttpHandler next) {
+        this.next = next;
+    }
+
+    @Override
+    public void handleRequest(HttpServerExchange exchange) throws Exception {
+        LazyConduitWrapper<StreamSourceConduit> requestConduitWrapper = new LazyConduitWrapper<StreamSourceConduit>() {
+            @Override
+            protected StreamSourceConduit create(ConduitFactory<StreamSourceConduit> factory, HttpServerExchange exchange) {
+                return new DebuggingStreamSourceConduit(factory.create());
+            }
+        };
+        LazyConduitWrapper<StreamSinkConduit> responseConduitWrapper = new LazyConduitWrapper<StreamSinkConduit>() {
+            @Override
+            protected StreamSinkConduit create(ConduitFactory<StreamSinkConduit> factory, HttpServerExchange exchange) {
+                return new DebuggingStreamSinkConduit(factory.create());
+            }
+        };
+        exchange.addRequestWrapper(requestConduitWrapper);
+        exchange.addResponseWrapper(responseConduitWrapper);
+
+        final StringBuilder sb = new StringBuilder();
+// Log pre-service information
+        final SecurityContext sc = exchange.getSecurityContext();
+        sb.append("\n----------------------------REQUEST---------------------------\n");
+        sb.append("               URI=").append(exchange.getRequestURI()).append("\n");
+        sb.append(" characterEncoding=").append(exchange.getRequestHeaders().get(Headers.CONTENT_ENCODING)).append("\n");
+        sb.append("     contentLength=").append(exchange.getRequestContentLength()).append("\n");
+        sb.append("       contentType=").append(exchange.getRequestHeaders().get(Headers.CONTENT_TYPE)).append("\n");
+        //sb.append("       contextPath=" + exchange.getContextPath());
+        if (sc != null) {
+            if (sc.isAuthenticated()) {
+                sb.append("          authType=").append(sc.getMechanismName()).append("\n");
+                sb.append("         principle=").append(sc.getAuthenticatedAccount().getPrincipal()).append("\n");
+            } else {
+                sb.append("          authType=none\n");
+            }
+        }
+
+        Map<String, Cookie> cookies = exchange.getRequestCookies();
+        if (cookies != null) {
+            for (Map.Entry<String, Cookie> entry : cookies.entrySet()) {
+                Cookie cookie = entry.getValue();
+                sb.append("            cookie=").append(cookie.getName()).append("=").append(cookie.getValue()).append("\n");
+            }
+        }
+        for (HeaderValues header : exchange.getRequestHeaders()) {
+            for (String value : header) {
+                sb.append("            header=").append(header.getHeaderName()).append("=").append(value).append("\n");
+            }
+        }
+        sb.append("            locale=").append(LocaleUtils.getLocalesFromHeader(exchange.getRequestHeaders().get(Headers.ACCEPT_LANGUAGE)))
+            .append("\n");
+        sb.append("            method=").append(exchange.getRequestMethod()).append("\n");
+        Map<String, Deque<String>> pnames = exchange.getQueryParameters();
+        for (Map.Entry<String, Deque<String>> entry : pnames.entrySet()) {
+            String pname = entry.getKey();
+            Iterator<String> pvalues = entry.getValue().iterator();
+            sb.append("         parameter=");
+            sb.append(pname);
+            sb.append('=');
+            while (pvalues.hasNext()) {
+                sb.append(pvalues.next());
+                if (pvalues.hasNext()) {
+                    sb.append(", ");
+                }
+            }
+            sb.append("\n");
+        }
+        //sb.append("          pathInfo=" + exchange.getPathInfo());
+        sb.append("          protocol=").append(exchange.getProtocol()).append("\n");
+        sb.append("       queryString=").append(exchange.getQueryString()).append("\n");
+        sb.append("        remoteAddr=").append(exchange.getSourceAddress()).append("\n");
+        sb.append("        remoteHost=").append(exchange.getSourceAddress().getHostName()).append("\n");
+        //sb.append("requestedSessionId=" + exchange.getRequestedSessionId());
+        sb.append("            scheme=").append(exchange.getRequestScheme()).append("\n");
+        sb.append("              host=").append(exchange.getRequestHeaders().getFirst(Headers.HOST)).append("\n");
+        sb.append("        serverPort=").append(exchange.getDestinationAddress().getPort()).append("\n");
+        //sb.append("       servletPath=" + exchange.getServletPath());
+        sb.append("          isSecure=").append(exchange.isSecure()).append("\n");
+
+        exchange.addExchangeCompleteListener((exchange1, nextListener) -> {
+            StreamSourceConduit sourceConduit = requestConduitWrapper.get();
+            if (sourceConduit instanceof ConduitWithDump) {
+                ConduitWithDump conduitWithDump = (ConduitWithDump) sourceConduit;
+                sb.append("body=\n");
+                sb.append(conduitWithDump.dump()).append("\n");
+            }
+
+            // Log post-service information
+            sb.append("--------------------------RESPONSE--------------------------\n");
+            if (sc != null) {
+                if (sc.isAuthenticated()) {
+                    sb.append("          authType=").append(sc.getMechanismName()).append("\n");
+                    sb.append("         principle=").append(sc.getAuthenticatedAccount().getPrincipal()).append("\n");
+                } else {
+                    sb.append("          authType=none\n");
+                }
+            }
+            sb.append("     contentLength=").append(exchange1.getResponseContentLength()).append("\n");
+            sb.append("       contentType=").append(exchange1.getResponseHeaders().getFirst(Headers.CONTENT_TYPE)).append("\n");
+            Map<String, Cookie> cookies1 = exchange1.getResponseCookies();
+            if (cookies1 != null) {
+                for (Cookie cookie : cookies1.values()) {
+                    sb.append("            cookie=").append(cookie.getName()).append("=").append(cookie.getValue()).append("; domain=")
+                        .append(cookie.getDomain()).append("; path=").append(cookie.getPath()).append("\n");
+                }
+            }
+            for (HeaderValues header : exchange1.getResponseHeaders()) {
+                for (String value : header) {
+                    sb.append("            header=").append(header.getHeaderName()).append("=").append(value).append("\n");
+                }
+            }
+            sb.append("            status=").append(exchange1.getStatusCode()).append("\n");
+            StreamSinkConduit streamSinkConduit = responseConduitWrapper.get();
+            if (streamSinkConduit instanceof ConduitWithDump) {
+                ConduitWithDump conduitWithDump = (ConduitWithDump) streamSinkConduit;
+                sb.append("body=\n");
+                sb.append(conduitWithDump.dump());
+
+            }
+
+            sb.append("\n==============================================================");
+
+
+            nextListener.proceed();
+            LOGGER.info(sb.toString());
+        });
+
+
+        // Perform the exchange
+        next.handleRequest(exchange);
+    }
+}