🚧 Improved access log

src/main/java/dev/dinauer/oidcproxy/Resource.java

@@ -1,8 +1,10 @@
 package dev.dinauer.oidcproxy;
 
 import dev.dinauer.oidcproxy.callback.CallbackService;
+import dev.dinauer.oidcproxy.proxy.AccessLog;
 import dev.dinauer.oidcproxy.proxy.ForwardService;
 import dev.dinauer.oidcproxy.proxy.ResponseHandler;
+import dev.dinauer.oidcproxy.proxy.TimedHttpResponse;
 import dev.dinauer.oidcproxy.proxy.exception.ProxyHttpException;
 import dev.dinauer.oidcproxy.proxy.exception.TokenNotFoundException;
 import dev.dinauer.oidcproxy.startup.PathConverter;
@@ -38,6 +40,9 @@ public class Resource
     @Inject
     LogoutService logoutService;
 
+    @Inject
+    AccessLog accessLog;
+
     @Route(path = "/auth/callback", order = 0)
     @Blocking
     public void callback(@Context RoutingContext context)
@@ -72,16 +77,16 @@ public class Resource
     private void route(RoutingContext context, String path, ProxyRoute route)
     {
         List<String> requestSegments = PathConverter.toSegments(path);
-        LOG.info("Matched route with target '{}'", route.target());
         try
         {
             String targetURI = route.target() + PathConverter.toPath(requestSegments);
-            HttpResponse<byte[]> response = forwardService.send(context, targetURI, route.strategy());
+            TimedHttpResponse<byte[]> response = forwardService.send(context, targetURI, route.strategy());
-            ResponseHandler.success(context, response);
+            accessLog.log(AccessLog.Type.INFO, context, PathConverter.toPath(requestSegments), route.target(), response.response().statusCode(), response.time());
+            ResponseHandler.success(context, response.response());
         }
         catch (ProxyHttpException e)
         {
-            LOG.error("Upstream returned error status {}.", e.getStatusCode(), e);
+            accessLog.log(AccessLog.Type.ERROR, context, PathConverter.toPath(requestSegments), route.target(), e.getStatusCode(), e.getTime());
             ResponseHandler.error(context, e.getStatusCode());
         }
         catch (TokenNotFoundException e)
@@ -97,7 +102,7 @@ public class Resource
         }
         catch (Exception e)
         {
-            LOG.error("Error occurred on upstream.", e);
+            accessLog.logUpstream(context, PathConverter.toPath(requestSegments), route.target());
             ResponseHandler.error(context, 502);
         }
     }

src/main/java/dev/dinauer/oidcproxy/proxy/AccessLog.java

@@ -0,0 +1,41 @@
+package dev.dinauer.oidcproxy.proxy;
+
+import dev.dinauer.oidcproxy.startup.PathConverter;
+import io.vertx.ext.web.RoutingContext;
+import jakarta.enterprise.context.ApplicationScoped;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+@ApplicationScoped
+public class AccessLog
+{
+    private static final Logger LOG = LoggerFactory.getLogger(AccessLog.class);
+
+    public void log(Type type, RoutingContext context, String request, String target, int statusCode, long time)
+    {
+        String log = String.format("[%s] [%s %s] %s - %s - %sms", context.request().remoteAddress().host(), context.request().method().toString().toUpperCase(), request, target, statusCode, time);
+        switch (type)
+        {
+            case INFO ->
+            {
+                LOG.info(log);
+            }
+            case ERROR ->
+            {
+                LOG.error(log);
+            }
+        }
+    }
+
+    public void logUpstream(RoutingContext context, String request, String target)
+    {
+        String log = String.format("[%s] [%s %s] %s - UPSTREAM ERROR", context.request().remoteAddress().host(), context.request().method().toString().toUpperCase(), request, target);
+        LOG.error(log);
+    }
+
+
+    public enum Type
+    {
+        INFO, ERROR
+    }
+}

src/main/java/dev/dinauer/oidcproxy/proxy/ForwardService.java

@@ -23,7 +23,7 @@ public class ForwardService
     @Inject
     HeaderFilter headerFilter;
 
-    public HttpResponse<byte[]> send(RoutingContext context, String route, String strategy) throws IOException, InterruptedException, ProxyHttpException, TokenNotFoundException
+    public TimedHttpResponse<byte[]> send(RoutingContext context, String route, String strategy) throws IOException, InterruptedException, ProxyHttpException, TokenNotFoundException
     {
         HttpRequestBuilder builder = HttpRequestBuilder.create();
         builder.setUri(route);
@@ -32,12 +32,16 @@ public class ForwardService
         builder.setHeaders(headerFilter.filter(context.request(), strategy));
         builder.setBody(extractBody(context));
 
+        long start = System.currentTimeMillis();
         HttpResponse<byte[]> response = CLIENT.send(builder.build(), HttpResponse.BodyHandlers.ofByteArray());
+        long end = System.currentTimeMillis();
+
+        long time = end - start;
         if (response.statusCode() < 400)
         {
-            return response;
+            return new TimedHttpResponse<>(time, response);
         }
-        throw new ProxyHttpException(response.statusCode());
+        throw new ProxyHttpException(time, response.statusCode());
     }
 
     private byte[] extractBody(RoutingContext context)

src/main/java/dev/dinauer/oidcproxy/proxy/TimedHttpResponse.java

@@ -0,0 +1,7 @@
+package dev.dinauer.oidcproxy.proxy;
+
+import java.net.http.HttpResponse;
+
+public record TimedHttpResponse<T>(long time, HttpResponse<T> response)
+{
+}

src/main/java/dev/dinauer/oidcproxy/proxy/exception/ProxyHttpException.java

@@ -2,13 +2,20 @@ package dev.dinauer.oidcproxy.proxy.exception;
 
 public class ProxyHttpException extends Exception
 {
+    private final long time;
     private final int statusCode;
 
-    public ProxyHttpException(int statusCode)
+    public ProxyHttpException(long time, int statusCode)
     {
+        this.time = time;
         this.statusCode = statusCode;
     }
 
+    public long getTime()
+    {
+        return time;
+    }
+
     public int getStatusCode()
     {
         return statusCode;

src/main/java/dev/dinauer/oidcproxy/request/HttpRequestBuilder.java

@@ -10,10 +10,14 @@ import java.net.http.HttpRequest;
 import java.nio.charset.StandardCharsets;
 import java.util.List;
 import java.util.Map;
+import java.util.Optional;
+import java.util.Set;
 import java.util.stream.Collectors;
 
 public class HttpRequestBuilder
 {
+    private static final Set<String> DISALLOWED_HEADERS = Set.of("connection", "content-length", "expect", "host", "upgrade");
+
     private static final Logger LOG = LoggerFactory.getLogger(HttpRequestBuilder.class);
 
     private String method;
@@ -57,20 +61,11 @@ public class HttpRequestBuilder
         HttpRequest.Builder builder = HttpRequest.newBuilder();
         builder.uri(buildURI(this.uri, this.params));
         builder.method(method, buildBody(body));
-
+        for (Map.Entry<String, String> element : Optional.ofNullable(this.headers).orElse(List.of()))
-        if (this.headers != null)
         {
-            for (Map.Entry<String, String> element : this.headers)
+            if (!DISALLOWED_HEADERS.contains(element.getKey()))
-            {
-                try
             {
                 builder.setHeader(element.getKey(), element.getValue());
-                    LOG.info("added header " + element.getKey());
-                }
-                catch (Exception e)
-                {
-                    LOG.info("Failed to add header.", e);
-                }
             }
         }
         return builder.build();