Jetty 9.4.x 3018 request logging bad messages (#3020)

Issue #3018 improve logging and handling of slow data rates.

* Slow data rates now result in aborted channels, but exception is still thrown.  Test for 408 in requestLog
* Updated many RequestLog usages to use Server.setRequestLog rather than a RequestLogHandler
* Fixed javadoc
* removed BadRequestLogHandlerTest (tested in RequestLogTest)
* added JMH to show the future of request logging for #113
* copyright header.
* Updates from review
* Revert to throwing BadMessageException
* BME ensures a 408 is logged rather than a 500

Signed-off-by: Greg Wilkins <gregw@webtide.com>

examples/embedded/src/main/java/org/eclipse/jetty/embedded/LikeJettyXml.java

@@ -44,7 +44,6 @@ import org.eclipse.jetty.server.SslConnectionFactory;
 import org.eclipse.jetty.server.handler.ContextHandlerCollection;
 import org.eclipse.jetty.server.handler.DefaultHandler;
 import org.eclipse.jetty.server.handler.HandlerCollection;
-import org.eclipse.jetty.server.handler.RequestLogHandler;
 import org.eclipse.jetty.server.handler.StatisticsHandler;
 import org.eclipse.jetty.util.ssl.SslContextFactory;
 import org.eclipse.jetty.util.thread.QueuedThreadPool;
@@ -214,9 +213,7 @@ public class LikeJettyXml
         requestLog.setExtended(true);
         requestLog.setLogCookies(false);
         requestLog.setLogTimeZone("GMT");
-        RequestLogHandler requestLogHandler = new RequestLogHandler();
+        server.setRequestLog(requestLog);
-        requestLogHandler.setRequestLog(requestLog);
-        handlers.addHandler(requestLogHandler);
 
 
         // === jetty-lowresources.xml ===

examples/embedded/src/main/java/org/eclipse/jetty/embedded/ManyHandlers.java

@@ -35,7 +35,6 @@ import org.eclipse.jetty.server.handler.DefaultHandler;
 import org.eclipse.jetty.server.handler.HandlerCollection;
 import org.eclipse.jetty.server.handler.HandlerList;
 import org.eclipse.jetty.server.handler.HandlerWrapper;
-import org.eclipse.jetty.server.handler.RequestLogHandler;
 import org.eclipse.jetty.server.handler.gzip.GzipHandler;
 import org.eclipse.jetty.util.ajax.JSON;
 
@@ -115,13 +114,12 @@ public class ManyHandlers
         HandlerWrapper wrapper = new WelcomeWrapHandler();
         Handler hello = new HelloHandler();
         Handler dft = new DefaultHandler();
-        RequestLogHandler requestLog = new RequestLogHandler();
 
         // configure request logging
         File requestLogFile = File.createTempFile("demo", "log");
         NCSARequestLog ncsaLog = new NCSARequestLog(
                 requestLogFile.getAbsolutePath());
-        requestLog.setRequestLog(ncsaLog);
+        server.setRequestLog(ncsaLog);
 
         // create the handler collections
         HandlerCollection handlers = new HandlerCollection();
@@ -129,20 +127,8 @@ public class ManyHandlers
 
         // link them all together
         wrapper.setHandler(hello);
-        list.setHandlers(new Handler[] { param, new GzipHandler(), dft });
+        list.setHandlers(new Handler[] { param, new GzipHandler() });
-        handlers.setHandlers(new Handler[] { list, requestLog });
+        handlers.setHandlers(new Handler[] { list, dft });
-
-        // Handler tree looks like the following
-        // <pre>
-        // Server
-        // + HandlerCollection
-        // . + HandlerList
-        // . | + param (ParamHandler)
-        // . | + wrapper (WelcomeWrapHandler)
-        // . | | \ hello (HelloHandler)
-        // . | \ dft (DefaultHandler)
-        // . \ requestLog (RequestLogHandler)
-        // </pre>
 
         server.setHandler(handlers);
 

jetty-ant/src/main/java/org/eclipse/jetty/ant/ServerProxyImpl.java

@@ -40,7 +40,6 @@ import org.eclipse.jetty.server.handler.ContextHandler;
 import org.eclipse.jetty.server.handler.ContextHandlerCollection;
 import org.eclipse.jetty.server.handler.DefaultHandler;
 import org.eclipse.jetty.server.handler.HandlerCollection;
-import org.eclipse.jetty.server.handler.RequestLogHandler;
 import org.eclipse.jetty.util.Scanner;
 import org.eclipse.jetty.util.resource.Resource;
 import org.eclipse.jetty.xml.XmlConfiguration;
@@ -407,9 +406,8 @@ public class ServerProxyImpl implements ServerProxy
      */
     private void configureHandlers()
     {
-        RequestLogHandler requestLogHandler = new RequestLogHandler();
         if (requestLog != null)
-            requestLogHandler.setRequestLog(requestLog);
+            server.setRequestLog(requestLog);
 
         contexts = (ContextHandlerCollection) server
                 .getChildHandlerByClass(ContextHandlerCollection.class);
@@ -422,8 +420,7 @@ public class ServerProxyImpl implements ServerProxy
             {
                 handlers = new HandlerCollection();
                 server.setHandler(handlers);
-                handlers.setHandlers(new Handler[] { contexts, new DefaultHandler(),
+                handlers.setHandlers(new Handler[] { contexts, new DefaultHandler() });
-                        requestLogHandler });
             }
             else
             {

jetty-jmh/src/main/java/org/eclipse/jetty/requestlog/jmh/RequestLogBenchmark.java

@@ -0,0 +1,222 @@
+//
+//  ========================================================================
+//  Copyright (c) 1995-2018 Mort Bay Consulting Pty. Ltd.
+//  ------------------------------------------------------------------------
+//  All rights reserved. This program and the accompanying materials
+//  are made available under the terms of the Eclipse Public License v1.0
+//  and Apache License v2.0 which accompanies this distribution.
+//
+//      The Eclipse Public License is available at
+//      http://www.eclipse.org/legal/epl-v10.html
+//
+//      The Apache License v2.0 is available at
+//      http://www.opensource.org/licenses/apache2.0.php
+//
+//  You may elect to redistribute this code under either of these licenses.
+//  ========================================================================
+//
+
+package org.eclipse.jetty.requestlog.jmh;
+
+import static java.lang.invoke.MethodHandles.dropArguments;
+import static java.lang.invoke.MethodHandles.foldArguments;
+import static java.lang.invoke.MethodType.methodType;
+
+import java.lang.invoke.MethodHandle;
+import java.lang.invoke.MethodHandles;
+import java.lang.invoke.MethodType;
+import java.util.concurrent.ThreadLocalRandom;
+import java.util.concurrent.TimeUnit;
+
+import org.eclipse.jetty.util.TypeUtil;
+import org.openjdk.jmh.annotations.Benchmark;
+import org.openjdk.jmh.annotations.BenchmarkMode;
+import org.openjdk.jmh.annotations.Measurement;
+import org.openjdk.jmh.annotations.Mode;
+import org.openjdk.jmh.annotations.Scope;
+import org.openjdk.jmh.annotations.State;
+import org.openjdk.jmh.annotations.Threads;
+import org.openjdk.jmh.annotations.Warmup;
+import org.openjdk.jmh.profile.GCProfiler;
+import org.openjdk.jmh.runner.Runner;
+import org.openjdk.jmh.runner.RunnerException;
+import org.openjdk.jmh.runner.options.Options;
+import org.openjdk.jmh.runner.options.OptionsBuilder;
+
+
+
+@State(Scope.Benchmark)
+@Threads(4)
+@Warmup(iterations = 7, time = 500, timeUnit = TimeUnit.MILLISECONDS)
+@Measurement(iterations = 7, time = 500, timeUnit = TimeUnit.MILLISECONDS)
+public class RequestLogBenchmark
+{
+
+    public static void append(String s, StringBuilder b)
+    {
+        b.append(s);
+    }
+
+    public static void logURI(StringBuilder b, String request)
+    {
+        b.append(request);
+    }
+
+    public static void logLength(StringBuilder b, String request)
+    {
+        b.append(request.length());
+    }
+
+    public static void logAddr(StringBuilder b, String request)
+    {
+        try
+        {
+            TypeUtil.toHex(request.hashCode(), b);
+        }
+        catch(Exception e)
+        {
+            throw new RuntimeException(e);
+        }
+    }
+
+    private ThreadLocal<StringBuilder> buffers = new ThreadLocal<StringBuilder>()
+    {
+        @Override
+        protected StringBuilder initialValue()
+        {
+            return new StringBuilder(256);
+        }
+    };
+    MethodHandle logHandle;
+    Object[] iteratedLog;
+
+    public RequestLogBenchmark()
+    {
+        try
+        {
+            MethodType logType = methodType(Void.TYPE, StringBuilder.class, String.class);
+
+            MethodHandle append = MethodHandles.lookup()
+                .findStatic(RequestLogBenchmark.class, "append", methodType(Void.TYPE, String.class, StringBuilder.class));
+            MethodHandle logURI = MethodHandles.lookup().findStatic(RequestLogBenchmark.class, "logURI", logType);
+            MethodHandle logAddr = MethodHandles.lookup().findStatic(RequestLogBenchmark.class, "logAddr", logType);
+            MethodHandle logLength = MethodHandles.lookup().findStatic(RequestLogBenchmark.class, "logLength", logType);
+
+            // setup iteration
+            iteratedLog = new Object[]
+                {
+                    logURI,
+                    " - ",
+                    logAddr,
+                    " ",
+                    logLength,
+                    "\n"
+                };
+
+            // setup methodHandle
+            logHandle = dropArguments(append.bindTo("\n"), 1, String.class);
+            logHandle = foldArguments(logHandle, logLength);
+            logHandle = foldArguments(logHandle, dropArguments(append.bindTo(" "), 1, String.class));
+            logHandle = foldArguments(logHandle, logAddr);
+            logHandle = foldArguments(logHandle, dropArguments(append.bindTo(" - "), 1, String.class));
+            logHandle = foldArguments(logHandle, logURI);
+
+        }
+        catch (Throwable th)
+        {
+            throw new RuntimeException(th);
+        }
+    }
+
+
+    public String logFixed(String request)
+    {
+        StringBuilder b = buffers.get();
+        logURI(b,request);
+        append(" - ",b);
+        logAddr(b,request);
+        append(" ",b);
+        logLength(b,request);
+        append("\n",b);
+        String l = b.toString();
+        b.setLength(0);
+        return l;
+    }
+
+    public String logIterate(String request)
+    {
+        try
+        {
+
+            StringBuilder b = buffers.get();
+            for (Object o : iteratedLog)
+            {
+                if (o instanceof String)
+                    append((String)o, b);
+                else if (o instanceof MethodHandle)
+                    ((MethodHandle)o).invoke(b, request);
+            }
+            String l = b.toString();
+            b.setLength(0);
+            return l;
+        }
+        catch(Throwable th)
+        {
+            throw new RuntimeException(th);
+        }
+    }
+
+    public String logMethodHandle(String request)
+    {
+        try
+        {
+            StringBuilder b = buffers.get();
+            logHandle.invoke(buffers.get(), request);
+            String l = b.toString();
+            b.setLength(0);
+            return l;
+        }
+        catch (Throwable th)
+        {
+            throw new RuntimeException(th);
+        }
+    }
+
+
+    @Benchmark
+    @BenchmarkMode({ Mode.Throughput})
+    public String testFixed()
+    {
+        return logFixed(Long.toString(ThreadLocalRandom.current().nextLong()));
+    };
+
+    @Benchmark
+    @BenchmarkMode({ Mode.Throughput})
+    public String testIterate()
+    {
+        return logIterate(Long.toString(ThreadLocalRandom.current().nextLong()));
+    };
+
+    @Benchmark
+    @BenchmarkMode({ Mode.Throughput})
+    public String testHandle()
+    {
+        return logMethodHandle(Long.toString(ThreadLocalRandom.current().nextLong()));
+    };
+
+
+    public static void main(String[] args) throws RunnerException
+    {
+        Options opt = new OptionsBuilder()
+            .include(RequestLogBenchmark.class.getSimpleName())
+            .warmupIterations(20)
+            .measurementIterations(10)
+            .addProfiler(GCProfiler.class)
+            .forks(1)
+            .threads(100)
+            .build();
+
+        new Runner(opt).run();
+    }
+
+}

jetty-maven-plugin/src/main/java/org/eclipse/jetty/maven/plugin/ServerSupport.java

@@ -33,7 +33,6 @@ import org.eclipse.jetty.server.Server;
 import org.eclipse.jetty.server.handler.ContextHandlerCollection;
 import org.eclipse.jetty.server.handler.DefaultHandler;
 import org.eclipse.jetty.server.handler.HandlerCollection;
-import org.eclipse.jetty.server.handler.RequestLogHandler;
 import org.eclipse.jetty.util.resource.Resource;
 import org.eclipse.jetty.webapp.Configuration;
 import org.eclipse.jetty.webapp.WebAppContext;
@@ -69,9 +68,8 @@ public class ServerSupport
             throw new IllegalArgumentException ("Server is null");
 
         DefaultHandler defaultHandler = new DefaultHandler();
-        RequestLogHandler requestLogHandler = new RequestLogHandler();
         if (requestLog != null)
-            requestLogHandler.setRequestLog(requestLog);
+            server.setRequestLog(requestLog);
 
         ContextHandlerCollection contexts = findContextHandlerCollection(server);
         if (contexts == null)
@@ -82,7 +80,7 @@ public class ServerSupport
             {
                 handlers = new HandlerCollection();               
                 server.setHandler(handlers);                            
-                handlers.setHandlers(new Handler[]{contexts, defaultHandler, requestLogHandler});
+                handlers.setHandlers(new Handler[]{contexts, defaultHandler});
             }
             else
             {

jetty-runner/src/main/java/org/eclipse/jetty/runner/Runner.java

@@ -43,7 +43,6 @@ import org.eclipse.jetty.server.handler.ContextHandler;
 import org.eclipse.jetty.server.handler.ContextHandlerCollection;
 import org.eclipse.jetty.server.handler.DefaultHandler;
 import org.eclipse.jetty.server.handler.HandlerCollection;
-import org.eclipse.jetty.server.handler.RequestLogHandler;
 import org.eclipse.jetty.server.handler.StatisticsHandler;
 import org.eclipse.jetty.server.session.SessionHandler;
 import org.eclipse.jetty.servlet.ServletContextHandler;
@@ -88,7 +87,6 @@ public class Runner
     protected URLClassLoader _classLoader;
     protected Classpath _classpath = new Classpath();
     protected ContextHandlerCollection _contexts;
-    protected RequestLogHandler _logHandler;
     protected String _logFile;
     protected ArrayList<String> _configFiles;
     protected boolean _enableStats=false;
@@ -392,14 +390,6 @@ public class Runner
                             handlers.addHandler(new DefaultHandler());
                         }
 
-                        //ensure a log handler is present
-                        _logHandler = (RequestLogHandler) handlers.getChildHandlerByClass(RequestLogHandler.class);
-                        if (_logHandler == null) 
-                        {
-                            _logHandler = new RequestLogHandler();
-                            handlers.addHandler(_logHandler);
-                        }
-
 
                         //check a connector is configured to listen on
                         Connector[] connectors = _server.getConnectors();
@@ -509,7 +499,7 @@ public class Runner
         {
             NCSARequestLog requestLog = new NCSARequestLog(_logFile);
             requestLog.setExtended(false);
-            _logHandler.setRequestLog(requestLog);
+            _server.setRequestLog(requestLog);
         }
     }
     

jetty-server/src/main/java/org/eclipse/jetty/server/HttpChannel.java

@@ -888,7 +888,6 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
     @Override
     public void write(ByteBuffer content, boolean complete, Callback callback)
     {
-        _written+=BufferUtil.length(content);
         sendResponse(null,content,complete,callback);
     }
 
@@ -1226,18 +1225,21 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
     private class CommitCallback extends Callback.Nested
     {
         private final ByteBuffer _content;
+        private final int _length;
         private final boolean _complete;
 
         private CommitCallback(Callback callback, ByteBuffer content, boolean complete)
         {
             super(callback);
-            this._content = content == null ? BufferUtil.EMPTY_BUFFER : content.slice();
+            _content = content == null ? BufferUtil.EMPTY_BUFFER : content.slice();
-            this._complete = complete;
+            _length = _content.remaining();
+            _complete = complete;
         }
 
         @Override
         public void succeeded()
         {
+            _written += _length;
             super.succeeded();
             notifyResponseCommit(_request);
             if (_content.hasRemaining())
@@ -1299,18 +1301,21 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor
     private class ContentCallback extends Callback.Nested
     {
         private final ByteBuffer _content;
+        private final int _length;
         private final boolean _complete;
 
         private ContentCallback(Callback callback, ByteBuffer content, boolean complete)
         {
             super(callback);
-            this._content = content == null ? BufferUtil.EMPTY_BUFFER : content.slice();
+            _content = content == null ? BufferUtil.EMPTY_BUFFER : content.slice();
-            this._complete = complete;
+            _length = _content.remaining();
+            _complete = complete;
         }
 
         @Override
         public void succeeded()
         {
+            _written += _length;
             super.succeeded();
             if (_content.hasRemaining())
                 notifyResponseContent(_request, _content);

jetty-server/src/main/java/org/eclipse/jetty/server/HttpInput.java

@@ -286,7 +286,12 @@ public class HttpInput extends ServletInputStream implements Runnable
                 {
                     long minimum_data = minRequestDataRate * TimeUnit.NANOSECONDS.toMillis(period) / TimeUnit.SECONDS.toMillis(1);
                     if (_contentArrived < minimum_data)
-                        throw new BadMessageException(HttpStatus.REQUEST_TIMEOUT_408,String.format("Request content data rate < %d B/s",minRequestDataRate));
+                    {
+                        BadMessageException bad = new BadMessageException(HttpStatus.REQUEST_TIMEOUT_408,
+                            String.format("Request content data rate < %d B/s", minRequestDataRate));
+                        _channelState.getHttpChannel().abort(bad);
+                        throw bad;
+                    }
                 }
             }
 

jetty-server/src/main/java/org/eclipse/jetty/server/HttpOutput.java

@@ -25,6 +25,7 @@ import java.nio.channels.ReadableByteChannel;
 import java.nio.channels.WritePendingException;
 import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicReference;
+
 import javax.servlet.RequestDispatcher;
 import javax.servlet.ServletOutputStream;
 import javax.servlet.ServletRequest;
@@ -934,7 +935,11 @@ public class HttpOutput extends ServletOutputStream implements Runnable
         if (LOG.isDebugEnabled())
             LOG.debug("Flushed bytes min/actual {}/{}", minFlushed, _flushed);
         if (_flushed < minFlushed)
-            throw new IOException(String.format("Response content data rate < %d B/s", minDataRate));
+        {
+            IOException ioe = new IOException(String.format("Response content data rate < %d B/s", minDataRate));
+            _channel.abort(ioe);
+            throw ioe;
+        }
     }
 
     public void recycle()

jetty-server/src/main/java/org/eclipse/jetty/server/handler/RequestLogHandler.java

@@ -31,11 +31,11 @@ import org.eclipse.jetty.server.Server;
 
 
 /**
- * RequestLogHandler.
+ * <p>This handler provides an alternate way (other than {@link Server#setRequestLog(RequestLog)})
- * This handler can be used to wrap an individual context for context logging.
+ * to log request, that can be applied to a particular handler (eg context).
- * To set a {@link RequestLog} instance for the entire {@link Server}, use 
+ * This handler can be used to wrap an individual context for context logging, or can be listed
- * {@link Server#setRequestLog(RequestLog)} instead of this handler.
+ * prior to a handler.
- *
+ * </p>
  * @see Server#setRequestLog(RequestLog)
  */
 public class RequestLogHandler extends HandlerWrapper

jetty-server/src/test/java/org/eclipse/jetty/server/handler/BadRequestLogHandlerTest.java

@@ -1,194 +0,0 @@
-//
-//  ========================================================================
-//  Copyright (c) 1995-2018 Mort Bay Consulting Pty. Ltd.
-//  ------------------------------------------------------------------------
-//  All rights reserved. This program and the accompanying materials
-//  are made available under the terms of the Eclipse Public License v1.0
-//  and Apache License v2.0 which accompanies this distribution.
-//
-//      The Eclipse Public License is available at
-//      http://www.eclipse.org/legal/epl-v10.html
-//
-//      The Apache License v2.0 is available at
-//      http://www.opensource.org/licenses/apache2.0.php
-//
-//  You may elect to redistribute this code under either of these licenses.
-//  ========================================================================
-//
-
-package org.eclipse.jetty.server.handler;
-
-import static org.hamcrest.MatcherAssert.assertThat;
-import static org.hamcrest.Matchers.is;
-import static org.junit.jupiter.api.Assertions.assertTimeoutPreemptively;
-
-import java.io.IOException;
-import java.io.InputStream;
-import java.io.InputStreamReader;
-import java.io.OutputStream;
-import java.io.OutputStreamWriter;
-import java.io.StringReader;
-import java.io.StringWriter;
-import java.net.InetAddress;
-import java.net.InetSocketAddress;
-import java.net.Socket;
-import java.net.SocketAddress;
-import java.nio.charset.StandardCharsets;
-import java.time.Duration;
-import java.util.ArrayList;
-import java.util.List;
-import java.util.stream.Stream;
-
-import javax.servlet.ServletException;
-import javax.servlet.http.HttpServletRequest;
-import javax.servlet.http.HttpServletResponse;
-
-import org.eclipse.jetty.server.Connector;
-import org.eclipse.jetty.server.Request;
-import org.eclipse.jetty.server.RequestLog;
-import org.eclipse.jetty.server.Response;
-import org.eclipse.jetty.server.Server;
-import org.eclipse.jetty.server.ServerConnector;
-import org.eclipse.jetty.util.IO;
-import org.eclipse.jetty.util.component.AbstractLifeCycle;
-import org.eclipse.jetty.util.log.Log;
-import org.eclipse.jetty.util.log.Logger;
-import org.junit.jupiter.api.Disabled;
-import org.junit.jupiter.api.Tag;
-import org.junit.jupiter.params.ParameterizedTest;
-import org.junit.jupiter.params.provider.Arguments;
-import org.junit.jupiter.params.provider.MethodSource;
-
-/**
- * Testing oddball request scenarios (like error 400) where the error should
- * be logged 
- */
-@Tag("Unstable")
-@Disabled
-public class BadRequestLogHandlerTest
-{
-    private static final Logger LOG = Log.getLogger(BadRequestLogHandlerTest.class);
-    
-    public static class CaptureLog extends AbstractLifeCycle implements RequestLog
-    {
-        public List<String> captured = new ArrayList<>();
-
-        @Override
-        public void log(Request request, Response response)
-        {
-            int status = response.getCommittedMetaData().getStatus();
-            captured.add(String.format("%s %s %s %03d",request.getMethod(),request.getHttpURI(),request.getProtocol(),status));
-        }
-    }
-    
-    private static class HelloHandler extends AbstractHandler
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
-        {
-            response.setContentType("text/plain");
-            response.getWriter().print("Hello World");
-            baseRequest.setHandled(true);
-        }
-    }
-    
-    public static Stream<Arguments> data()
-    {
-        List<Object[]> data = new ArrayList<>();
-        
-        data.add(new String[]{ "GET /bad VER\r\n"
-                + "Host: localhost\r\n"
-                + "Connection: close\r\n\r\n" , 
-                "GET <invalidrequest> HTTP/1.1 400" });
-        data.add(new String[]{ "GET /%%adsasd HTTP/1.1\r\n"
-                + "Host: localhost\r\n"
-                + "Connection: close\r\n\r\n" , 
-                "GET <invalidrequest> HTTP/1.1 400" });
-        
-        return data.stream().map(Arguments::of);
-    }
-    
-    @ParameterizedTest
-    @MethodSource("data")
-    public void testLogHandler(String requestHeader, String expectedLog) throws Exception
-    {
-        Server server = new Server();
-        ServerConnector connector = new ServerConnector(server);
-        connector.setPort(0);
-        server.setConnectors(new Connector[] { connector });
-
-        CaptureLog captureLog = new CaptureLog();
-
-        RequestLogHandler requestLog = new RequestLogHandler();
-        requestLog.setRequestLog(captureLog);
-        
-        requestLog.setHandler(new HelloHandler());
-
-        server.setHandler(requestLog);
-
-        try
-        {
-            server.start();
-            
-            String host = connector.getHost();
-            if (host == null)
-            {
-                host = "localhost";
-            }
-
-            InetAddress destAddr = InetAddress.getByName(host);
-            int port = connector.getLocalPort();
-            SocketAddress endpoint = new InetSocketAddress(destAddr,port);
-
-            Socket socket = new Socket();
-            socket.setSoTimeout(1000);
-            socket.connect(endpoint);
-
-            assertTimeoutPreemptively(Duration.ofSeconds(4), ()-> {
-                try (OutputStream out = socket.getOutputStream();
-                     OutputStreamWriter writer = new OutputStreamWriter(out, StandardCharsets.UTF_8);
-                     InputStream in = socket.getInputStream();
-                     InputStreamReader reader = new InputStreamReader(in, StandardCharsets.UTF_8))
-                {
-                    StringReader request = new StringReader(requestHeader);
-                    IO.copy(request, writer);
-                    writer.flush();
-                    StringWriter response = new StringWriter();
-                    IO.copy(reader, response);
-                    LOG.info("Response: {}", response);
-                }
-                finally
-                {
-                    socket.close();
-                }
-            });
-
-            assertRequestLog(expectedLog, captureLog);
-        }
-        finally
-        {
-            server.stop();
-        }
-    }
-    
-    private void assertRequestLog(final String expectedLog, CaptureLog captureLog)
-    {
-        int captureCount = captureLog.captured.size();
-
-        if (captureCount != 1)
-        {
-            LOG.warn("Capture Log size is {}, expected to be 1",captureCount);
-            if (captureCount > 1)
-            {
-                for (int i = 0; i < captureCount; i++)
-                {
-                    LOG.warn("[{}] {}",i,captureLog.captured.get(i));
-                }
-            }
-            assertThat("Capture Log Entry Count",captureLog.captured.size(),is(1));
-        }
-
-        String actual = captureLog.captured.get(0);
-        assertThat("Capture Log",actual,is(expectedLog));
-    }
-}

jetty-server/src/test/java/org/eclipse/jetty/server/handler/RequestLogHandlerTest.java

@@ -1,886 +0,0 @@
-//
-//  ========================================================================
-//  Copyright (c) 1995-2018 Mort Bay Consulting Pty. Ltd.
-//  ------------------------------------------------------------------------
-//  All rights reserved. This program and the accompanying materials
-//  are made available under the terms of the Eclipse Public License v1.0
-//  and Apache License v2.0 which accompanies this distribution.
-//
-//      The Eclipse Public License is available at
-//      http://www.eclipse.org/legal/epl-v10.html
-//
-//      The Apache License v2.0 is available at
-//      http://www.opensource.org/licenses/apache2.0.php
-//
-//  You may elect to redistribute this code under either of these licenses.
-//  ========================================================================
-//
-
-package org.eclipse.jetty.server.handler;
-
-import static org.hamcrest.MatcherAssert.assertThat;
-import static org.hamcrest.Matchers.is;
-import static org.hamcrest.Matchers.notNullValue;
-
-import java.io.IOException;
-import java.io.InputStream;
-import java.io.InputStreamReader;
-import java.io.PrintWriter;
-import java.io.StringWriter;
-import java.net.HttpURLConnection;
-import java.net.URI;
-import java.util.ArrayList;
-import java.util.List;
-import java.util.stream.Stream;
-
-import javax.servlet.AsyncContext;
-import javax.servlet.AsyncEvent;
-import javax.servlet.AsyncListener;
-import javax.servlet.RequestDispatcher;
-import javax.servlet.ServletException;
-import javax.servlet.http.HttpServletRequest;
-import javax.servlet.http.HttpServletResponse;
-
-import org.eclipse.jetty.server.Connector;
-import org.eclipse.jetty.server.Handler;
-import org.eclipse.jetty.server.HttpChannel;
-import org.eclipse.jetty.server.HttpChannelState;
-import org.eclipse.jetty.server.Request;
-import org.eclipse.jetty.server.RequestLog;
-import org.eclipse.jetty.server.Response;
-import org.eclipse.jetty.server.Server;
-import org.eclipse.jetty.server.ServerConnector;
-import org.eclipse.jetty.toolchain.test.IO;
-import org.eclipse.jetty.util.component.AbstractLifeCycle;
-import org.eclipse.jetty.util.log.Log;
-import org.eclipse.jetty.util.log.Logger;
-import org.eclipse.jetty.util.log.StacklessLogging;
-import org.junit.jupiter.api.Disabled;
-import org.junit.jupiter.api.Tag;
-import org.junit.jupiter.params.ParameterizedTest;
-import org.junit.jupiter.params.provider.Arguments;
-import org.junit.jupiter.params.provider.MethodSource;
-
-/**
- * Tests for RequestLogHandler behavior.
- * <p>
- * Tests different request handler behavior against different server+error configurations
- */
-@Tag("Unstable")
-@Disabled
-public class RequestLogHandlerTest
-{
-    private static final Logger LOG = Log.getLogger(RequestLogHandlerTest.class);
-
-    public static class CaptureLog extends AbstractLifeCycle implements RequestLog
-    {
-        public List<String> captured = new ArrayList<>();
-
-        @Override
-        public void log(Request request, Response response)
-        {
-            int status = response.getCommittedMetaData().getStatus();
-            captured.add(String.format("%s %s %s %03d",request.getMethod(),request.getRequestURI(),request.getProtocol(),status));
-        }
-    }
-
-    private static abstract class AbstractTestHandler extends AbstractHandler
-    {
-        @Override
-        public String toString()
-        {
-            return this.getClass().getSimpleName();
-        }
-    }
-
-    private static class HelloHandler extends AbstractTestHandler
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
-        {
-            response.setContentType("text/plain");
-            response.getWriter().print("Hello World");
-            baseRequest.setHandled(true);
-        }
-    }
-
-    private static class ResponseSendErrorHandler extends AbstractTestHandler
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
-        {
-            response.sendError(500,"Whoops");
-            baseRequest.setHandled(true);
-        }
-    }
-
-    private static class ServletExceptionHandler extends AbstractTestHandler
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
-        {
-            throw new ServletException("Whoops");
-        }
-    }
-
-    private static class IOExceptionHandler extends AbstractTestHandler
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
-        {
-            throw new IOException("Whoops");
-        }
-    }
-
-    private static class RuntimeExceptionHandler extends AbstractTestHandler
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
-        {
-            throw new RuntimeException("Whoops");
-        }
-    }
-
-    private static class AsyncOnTimeoutCompleteHandler extends AbstractTestHandler implements AsyncListener
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
-        {
-            AsyncContext ac = request.startAsync();
-            ac.setTimeout(1000);
-            ac.addListener(this);
-            baseRequest.setHandled(true);
-        }
-
-        @Override
-        public void onTimeout(AsyncEvent event) throws IOException
-        {
-            event.getAsyncContext().complete();
-        }
-
-        @Override
-        public void onStartAsync(AsyncEvent event) throws IOException
-        {
-        }
-
-        @Override
-        public void onError(AsyncEvent event) throws IOException
-        {
-        }
-
-        @Override
-        public void onComplete(AsyncEvent event) throws IOException
-        {
-        }
-    }
-
-    private static class AsyncOnTimeoutCompleteUnhandledHandler extends AbstractTestHandler implements AsyncListener
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
-        {
-            AsyncContext ac = request.startAsync();
-            ac.setTimeout(1000);
-            ac.addListener(this);
-        }
-
-        @Override
-        public void onTimeout(AsyncEvent event) throws IOException
-        {
-            event.getAsyncContext().complete();
-        }
-
-        @Override
-        public void onStartAsync(AsyncEvent event) throws IOException
-        {
-        }
-
-        @Override
-        public void onError(AsyncEvent event) throws IOException
-        {
-        }
-
-        @Override
-        public void onComplete(AsyncEvent event) throws IOException
-        {
-        }
-    }
-
-    private static class AsyncOnTimeoutDispatchHandler extends AbstractTestHandler implements AsyncListener
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
-        {
-            if (request.getAttribute("deep") == null)
-            {
-                AsyncContext ac = request.startAsync();
-                ac.setTimeout(1000);
-                ac.addListener(this);
-                baseRequest.setHandled(true);
-                request.setAttribute("deep",true);
-            }
-        }
-
-        @Override
-        public void onTimeout(AsyncEvent event) throws IOException
-        {
-            event.getAsyncContext().dispatch();
-        }
-
-        @Override
-        public void onStartAsync(AsyncEvent event) throws IOException
-        {
-        }
-
-        @Override
-        public void onError(AsyncEvent event) throws IOException
-        {
-        }
-
-        @Override
-        public void onComplete(AsyncEvent event) throws IOException
-        {
-        }
-    }
-
-    private static class AsyncOnStartIOExceptionHandler extends AbstractTestHandler implements AsyncListener
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
-        {
-            AsyncContext ac = request.startAsync();
-            ac.setTimeout(1000);
-            ac.addListener(this);
-            baseRequest.setHandled(true);
-        }
-
-        @Override
-        public void onTimeout(AsyncEvent event) throws IOException
-        {
-        }
-
-        @Override
-        public void onStartAsync(AsyncEvent event) throws IOException
-        {
-            event.getAsyncContext().complete();
-            throw new IOException("Whoops");
-        }
-
-        @Override
-        public void onError(AsyncEvent event) throws IOException
-        {
-            LOG.warn("onError() -> {}",event);
-        }
-
-        @Override
-        public void onComplete(AsyncEvent event) throws IOException
-        {
-        }
-    }
-
-    public static class OKErrorHandler extends ErrorHandler
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException
-        {
-            if (baseRequest.isHandled() || response.isCommitted())
-            {
-                return;
-            }
-
-            // collect error details
-            String reason = (response instanceof Response)?((Response)response).getReason():null;
-            int status = response.getStatus();
-
-            // intentionally set response status to OK (this is a test to see what is actually logged)
-            response.setStatus(200);
-            response.setContentType("text/plain");
-            PrintWriter out = response.getWriter();
-            out.printf("Error %d: %s%n",status,reason);
-            baseRequest.setHandled(true);
-        }
-    }
-
-    public static class DispatchErrorHandler extends ErrorHandler
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException
-        {
-            if (baseRequest.isHandled() || response.isCommitted())
-            {
-                return;
-            }
-
-            RequestDispatcher dispatcher = request.getRequestDispatcher("/errorok/");
-            assertThat("Dispatcher", dispatcher, notNullValue());
-
-            try
-            {
-                dispatcher.forward(request,response);
-            }
-            catch (ServletException e)
-            {
-                throw new IOException("Dispatch.forward failed",e);
-            }
-        }
-    }
-
-    public static class AltErrorHandler extends ErrorHandler
-    {
-        @Override
-        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException
-        {
-            if (baseRequest.isHandled() || response.isCommitted())
-            {
-                return;
-            }
-
-            // collect error details
-            String reason = (response instanceof Response)?((Response)response).getReason():null;
-            int status = response.getStatus();
-
-            // intentionally set response status to OK (this is a test to see what is actually logged)
-            response.setContentType("text/plain");
-            PrintWriter out = response.getWriter();
-            out.printf("Error %d: %s%n",status,reason);
-            baseRequest.setHandled(true);
-        }
-    }
-
-    public static Stream<Arguments> data()
-    {
-        List<Object[]> data = new ArrayList<>();
-
-        data.add(new Object[] { new HelloHandler(), "/test/", "GET /test/ HTTP/1.1 200" });
-        data.add(new Object[] { new AsyncOnTimeoutCompleteHandler(), "/test/", "GET /test/ HTTP/1.1 200" });
-        data.add(new Object[] { new AsyncOnTimeoutCompleteUnhandledHandler(), "/test/", "GET /test/ HTTP/1.1 200" });
-        data.add(new Object[] { new AsyncOnTimeoutDispatchHandler(), "/test/", "GET /test/ HTTP/1.1 200" });
-
-        data.add(new Object[] { new AsyncOnStartIOExceptionHandler(), "/test/", "GET /test/ HTTP/1.1 500" });
-        data.add(new Object[] { new ResponseSendErrorHandler(), "/test/", "GET /test/ HTTP/1.1 500" });
-        data.add(new Object[] { new ServletExceptionHandler(), "/test/", "GET /test/ HTTP/1.1 500" });
-        data.add(new Object[] { new IOExceptionHandler(), "/test/", "GET /test/ HTTP/1.1 500" });
-        data.add(new Object[] { new RuntimeExceptionHandler(), "/test/", "GET /test/ HTTP/1.1 500" });
-
-        return data.stream().map(Arguments::of);
-    }
-
-    /**
-     * Test a RequestLogHandler at the end of a HandlerCollection. all other configuration on server at defaults.
-     * @throws Exception if test failure
-     */
-    @ParameterizedTest
-    @MethodSource("data")
-    public void testLogHandlerCollection(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
-    {
-        Server server = new Server();
-        ServerConnector connector = new ServerConnector(server);
-        connector.setPort(0);
-        server.setConnectors(new Connector[] { connector });
-
-        CaptureLog captureLog = new CaptureLog();
-
-        RequestLogHandler requestLog = new RequestLogHandler();
-        requestLog.setRequestLog(captureLog);
-
-        HandlerCollection handlers = new HandlerCollection();
-        handlers.setHandlers(new Handler[] { testHandler, requestLog });
-        server.setHandler(handlers);
-
-        try
-        {
-            server.start();
-
-            String host = connector.getHost();
-            if (host == null)
-            {
-                host = "localhost";
-            }
-            int port = connector.getLocalPort();
-
-            URI serverUri = new URI("http",null,host,port,requestPath,null,null);
-
-            // Make call to test handler
-            HttpURLConnection connection = (HttpURLConnection)serverUri.toURL().openConnection();
-            try
-            {
-                connection.setAllowUserInteraction(false);
-
-                // log response status code
-                int statusCode = connection.getResponseCode();
-                LOG.debug("Response Status Code: {}",statusCode);
-
-                if (statusCode == 200)
-                {
-                    // collect response message and log it
-                    String content = getResponseContent(connection);
-                    LOG.debug("Response Content: {}",content);
-                }
-            }
-            finally
-            {
-                connection.disconnect();
-            }
-
-            assertRequestLog(expectedLogEntry, captureLog);
-        }
-        finally
-        {
-            server.stop();
-        }
-    }
-
-    @ParameterizedTest
-    @MethodSource("data")
-    public void testMultipleLogHandlers(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
-    {
-        Server server = new Server();
-        ServerConnector connector = new ServerConnector(server);
-        connector.setPort(0);
-        server.setConnectors(new Connector[]{connector});
-
-        List<CaptureLog> captureLogs = new ArrayList<>();
-        List<Handler> handlerList = new ArrayList<>();
-        handlerList.add(testHandler);
-
-        for (int i = 0; i < 4; ++i) {
-            CaptureLog captureLog = new CaptureLog();
-            captureLogs.add(captureLog);
-            RequestLogHandler requestLog = new RequestLogHandler();
-            requestLog.setRequestLog(captureLog);
-            handlerList.add(requestLog);
-        }
-
-        HandlerCollection handlers = new HandlerCollection();
-        handlers.setHandlers(handlerList.toArray(new Handler[0]));
-        server.setHandler(handlers);
-
-        try
-        {
-            server.start();
-
-            String host = connector.getHost();
-            if (host == null)
-            {
-                host = "localhost";
-            }
-            int port = connector.getLocalPort();
-
-            URI serverUri = new URI("http",null,host,port,requestPath,null,null);
-
-            // Make call to test handler
-            HttpURLConnection connection = (HttpURLConnection)serverUri.toURL().openConnection();
-            try
-            {
-                connection.setAllowUserInteraction(false);
-
-                // log response status code
-                int statusCode = connection.getResponseCode();
-                LOG.debug("Response Status Code: {}",statusCode);
-
-                if (statusCode == 200)
-                {
-                    // collect response message and log it
-                    String content = getResponseContent(connection);
-                    LOG.debug("Response Content: {}",content);
-                }
-            }
-            finally
-            {
-                connection.disconnect();
-            }
-
-            for (CaptureLog captureLog:captureLogs)
-                assertRequestLog(expectedLogEntry, captureLog);
-        }
-        finally
-        {
-            server.stop();
-        }
-    }
-
-    /**
-     * Test a RequestLogHandler at the end of a HandlerCollection and also with the default ErrorHandler as server bean in place.
-     * @throws Exception if test failure
-     */
-    @ParameterizedTest
-    @MethodSource("data")
-    public void testLogHandlerCollection_ErrorHandler_ServerBean(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
-    {
-        Server server = new Server();
-        ServerConnector connector = new ServerConnector(server);
-        connector.setPort(0);
-        server.setConnectors(new Connector[] { connector });
-
-        ErrorHandler errorHandler = new ErrorHandler();
-        server.addBean(errorHandler);
-
-        CaptureLog captureLog = new CaptureLog();
-
-        RequestLogHandler requestLog = new RequestLogHandler();
-        requestLog.setRequestLog(captureLog);
-
-        HandlerCollection handlers = new HandlerCollection();
-        handlers.setHandlers(new Handler[] { testHandler, requestLog });
-        server.setHandler(handlers);
-
-        try
-        {
-            server.start();
-
-            String host = connector.getHost();
-            if (host == null)
-            {
-                host = "localhost";
-            }
-            int port = connector.getLocalPort();
-
-            URI serverUri = new URI("http",null,host,port,requestPath,null,null);
-
-            // Make call to test handler
-            HttpURLConnection connection = (HttpURLConnection)serverUri.toURL().openConnection();
-            try
-            {
-                connection.setAllowUserInteraction(false);
-
-                // log response status code
-                int statusCode = connection.getResponseCode();
-                LOG.debug("Response Status Code: {}",statusCode);
-
-                if (statusCode == 200)
-                {
-                    // collect response message and log it
-                    String content = getResponseContent(connection);
-                    LOG.debug("Response Content: {}",content);
-                }
-            }
-            finally
-            {
-                connection.disconnect();
-            }
-
-            assertRequestLog(expectedLogEntry, captureLog);
-        }
-        finally
-        {
-            server.stop();
-        }
-    }
-
-    /**
-     * Test a RequestLogHandler at the end of a HandlerCollection and also with the ErrorHandler in place.
-     * @throws Exception if test failure
-     */
-    @ParameterizedTest
-    @MethodSource("data")
-    public void testLogHandlerCollection_AltErrorHandler(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
-    {
-        Server server = new Server();
-        ServerConnector connector = new ServerConnector(server);
-        connector.setPort(0);
-        server.setConnectors(new Connector[] { connector });
-        
-        AltErrorHandler errorDispatcher = new AltErrorHandler();
-        server.addBean(errorDispatcher);
-        
-        ContextHandlerCollection contexts = new ContextHandlerCollection();
-        ContextHandler errorContext = new ContextHandler("/errorpage");
-        errorContext.setHandler(new AltErrorHandler());
-        ContextHandler testContext = new ContextHandler("/test");
-        testContext.setHandler(testHandler);
-        contexts.addHandler(errorContext);
-        contexts.addHandler(testContext);
-
-        RequestLogHandler requestLog = new RequestLogHandler();
-        CaptureLog captureLog = new CaptureLog();
-        requestLog.setRequestLog(captureLog);
-
-        HandlerCollection handlers = new HandlerCollection();
-        handlers.setHandlers(new Handler[] { contexts, requestLog });
-        server.setHandler(handlers);
-
-        try
-        {
-            server.start();
-
-            String host = connector.getHost();
-            if (host == null)
-            {
-                host = "localhost";
-            }
-            int port = connector.getLocalPort();
-
-            URI serverUri = new URI("http",null,host,port,requestPath,null,null);
-
-            // Make call to test handler
-            HttpURLConnection connection = (HttpURLConnection)serverUri.toURL().openConnection();
-            try
-            {
-                connection.setAllowUserInteraction(false);
-
-                // log response status code
-                int statusCode = connection.getResponseCode();
-                LOG.debug("Response Status Code: {}",statusCode);
-
-                if (statusCode == 200)
-                {
-                    // collect response message and log it
-                    String content = getResponseContent(connection);
-                    LOG.debug("Response Content: {}",content);
-                }
-            }
-            finally
-            {
-                connection.disconnect();
-            }
-
-            assertRequestLog(expectedLogEntry, captureLog);
-        }
-        finally
-        {
-            server.stop();
-        }
-    }
-    
-    /**
-     * Test a RequestLogHandler at the end of a HandlerCollection and also with the ErrorHandler in place.
-     * @throws Exception if test failure
-     */
-    @ParameterizedTest
-    @MethodSource("data")
-    public void testLogHandlerCollection_OKErrorHandler(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
-    {
-        Server server = new Server();
-        ServerConnector connector = new ServerConnector(server);
-        connector.setPort(0);
-        server.setConnectors(new Connector[] { connector });
-        
-        OKErrorHandler errorDispatcher = new OKErrorHandler();
-        server.addBean(errorDispatcher);
-        
-        ContextHandlerCollection contexts = new ContextHandlerCollection();
-        ContextHandler errorContext = new ContextHandler("/errorpage");
-        errorContext.setHandler(new AltErrorHandler());
-        ContextHandler testContext = new ContextHandler("/test");
-        testContext.setHandler(testHandler);
-        contexts.addHandler(errorContext);
-        contexts.addHandler(testContext);
-
-        RequestLogHandler requestLog = new RequestLogHandler();
-        CaptureLog captureLog = new CaptureLog();
-        requestLog.setRequestLog(captureLog);
-
-        HandlerCollection handlers = new HandlerCollection();
-        handlers.setHandlers(new Handler[] { contexts, requestLog });
-        server.setHandler(handlers);
-
-        try
-        {
-            server.start();
-
-            String host = connector.getHost();
-            if (host == null)
-            {
-                host = "localhost";
-            }
-            int port = connector.getLocalPort();
-
-            URI serverUri = new URI("http",null,host,port,requestPath,null,null);
-
-            // Make call to test handler
-            HttpURLConnection connection = (HttpURLConnection)serverUri.toURL().openConnection();
-            try
-            {
-                connection.setAllowUserInteraction(false);
-
-                // log response status code
-                int statusCode = connection.getResponseCode();
-                LOG.debug("Response Status Code: {}",statusCode);
-
-                if (statusCode == 200)
-                {
-                    // collect response message and log it
-                    String content = getResponseContent(connection);
-                    LOG.debug("Response Content: {}",content);
-                }
-            }
-            finally
-            {
-                connection.disconnect();
-            }
-
-            assertRequestLog(expectedLogEntry, captureLog);
-        }
-        finally
-        {
-            server.stop();
-        }
-    }
-    
-    /**
-     * Test a RequestLogHandler at the end of a HandlerCollection and also with the ErrorHandler in place.
-     * @throws Exception if test failure
-     */
-    @ParameterizedTest
-    @MethodSource("data")
-    public void testLogHandlerCollection_DispatchErrorHandler(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
-    {
-        Server server = new Server();
-        ServerConnector connector = new ServerConnector(server);
-        connector.setPort(0);
-        server.setConnectors(new Connector[] { connector });
-        
-        DispatchErrorHandler errorDispatcher = new DispatchErrorHandler();
-        server.addBean(errorDispatcher);
-        
-        ContextHandlerCollection contexts = new ContextHandlerCollection();
-        ContextHandler errorContext = new ContextHandler("/errorok");
-        errorContext.setHandler(new OKErrorHandler());
-        ContextHandler testContext = new ContextHandler("/test");
-        testContext.setHandler(testHandler);
-        contexts.addHandler(errorContext);
-        contexts.addHandler(testContext);
-
-        RequestLogHandler requestLog = new RequestLogHandler();
-        CaptureLog captureLog = new CaptureLog();
-        requestLog.setRequestLog(captureLog);
-
-        HandlerCollection handlers = new HandlerCollection();
-        handlers.setHandlers(new Handler[] { contexts, requestLog });
-        server.setHandler(handlers);
-
-        try
-        {
-            server.start();
-
-            String host = connector.getHost();
-            if (host == null)
-            {
-                host = "localhost";
-            }
-            int port = connector.getLocalPort();
-
-            URI serverUri = new URI("http",null,host,port,requestPath,null,null);
-
-            // Make call to test handler
-            HttpURLConnection connection = (HttpURLConnection)serverUri.toURL().openConnection();
-            try
-            {
-                connection.setAllowUserInteraction(false);
-
-                // log response status code
-                int statusCode = connection.getResponseCode();
-                LOG.debug("Response Status Code: {}",statusCode);
-
-                if (statusCode == 200)
-                {
-                    // collect response message and log it
-                    String content = getResponseContent(connection);
-                    LOG.debug("Response Content: {}",content);
-                }
-            }
-            finally
-            {
-                connection.disconnect();
-            }
-
-            assertRequestLog(expectedLogEntry, captureLog);
-        }
-        finally
-        {
-            server.stop();
-        }
-    }
-
-    @ParameterizedTest
-    @MethodSource("data")
-    public void testLogHandlerWrapped(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
-    {
-        Server server = new Server();
-        ServerConnector connector = new ServerConnector(server);
-        connector.setPort(0);
-        server.setConnectors(new Connector[] { connector });
-
-        CaptureLog captureLog = new CaptureLog();
-
-        RequestLogHandler requestLog = new RequestLogHandler();
-        requestLog.setRequestLog(captureLog);
-
-        requestLog.setHandler(testHandler);
-
-        server.setHandler(requestLog);
-        
-        try (StacklessLogging ignore = new StacklessLogging(HttpChannel.class,HttpChannelState.class))
-        {
-            server.start();
-
-            String host = connector.getHost();
-            if (host == null)
-            {
-                host = "localhost";
-            }
-            int port = connector.getLocalPort();
-
-            URI serverUri = new URI("http",null,host,port,requestPath,null,null);
-
-            // Make call to test handler
-            HttpURLConnection connection = (HttpURLConnection)serverUri.toURL().openConnection();
-            try
-            {
-                connection.setAllowUserInteraction(false);
-
-                // log response status code
-                int statusCode = connection.getResponseCode();
-                LOG.info("Response Status Code: {}",statusCode);
-
-                if (statusCode == 200)
-                {
-                    // collect response message and log it
-                    String content = getResponseContent(connection);
-                    LOG.info("Response Content: {}",content);
-                }
-            }
-            finally
-            {
-                connection.disconnect();
-            }
-
-            assertRequestLog(expectedLogEntry, captureLog);
-        }
-        finally
-        {
-            server.stop();
-        }
-    }
-
-    private void assertRequestLog(final String expectedLogEntry, CaptureLog captureLog)
-    {
-        int captureCount = captureLog.captured.size();
-
-        if (captureCount != 1)
-        {
-            LOG.warn("Capture Log size is {}, expected to be 1",captureCount);
-            if (captureCount > 1)
-            {
-                for (int i = 0; i < captureCount; i++)
-                {
-                    LOG.warn("[{}] {}",i,captureLog.captured.get(i));
-                }
-            }
-            assertThat("Capture Log Entry Count",captureLog.captured.size(),is(1));
-        }
-
-        String actual = captureLog.captured.get(0);
-        assertThat("Capture Log",actual,is(expectedLogEntry));
-    }
-
-    private String getResponseContent(HttpURLConnection connection) throws IOException
-    {
-        try (InputStream in = connection.getInputStream(); InputStreamReader reader = new InputStreamReader(in))
-        {
-            StringWriter writer = new StringWriter();
-            IO.copy(reader,writer);
-            return writer.toString();
-        }
-    }
-}

jetty-server/src/test/java/org/eclipse/jetty/server/handler/RequestLogTest.java

@@ -18,31 +18,47 @@
 
 package org.eclipse.jetty.server.handler;
 
-import static org.hamcrest.Matchers.containsString;
 import static org.hamcrest.MatcherAssert.assertThat;
+import static org.hamcrest.Matchers.contains;
+import static org.hamcrest.Matchers.containsString;
 
 import java.io.IOException;
 import java.io.InputStream;
 import java.io.PrintWriter;
+import java.util.ArrayList;
 import java.util.Arrays;
-import java.util.concurrent.Exchanger;
+import java.util.List;
+import java.util.concurrent.BlockingQueue;
 import java.util.concurrent.TimeUnit;
+import java.util.stream.Stream;
 
+import javax.servlet.AsyncContext;
 import javax.servlet.ServletException;
 import javax.servlet.http.HttpServletRequest;
 import javax.servlet.http.HttpServletResponse;
 
+import org.eclipse.jetty.http.BadMessageException;
 import org.eclipse.jetty.server.AbstractNCSARequestLog;
+import org.eclipse.jetty.server.Handler;
 import org.eclipse.jetty.server.LocalConnector;
 import org.eclipse.jetty.server.Request;
+import org.eclipse.jetty.server.RequestLog;
+import org.eclipse.jetty.server.Response;
 import org.eclipse.jetty.server.Server;
+import org.eclipse.jetty.util.BlockingArrayQueue;
+import org.eclipse.jetty.util.component.AbstractLifeCycle;
 import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.Assertions;
+import org.junit.jupiter.api.Assumptions;
 import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
+import org.junit.jupiter.params.ParameterizedTest;
+import org.junit.jupiter.params.provider.Arguments;
+import org.junit.jupiter.params.provider.MethodSource;
 
 public class RequestLogTest
 {
-    Exchanger<String> _log;
+    Log _log;
     Server _server;
     LocalConnector _connector;
     
@@ -50,19 +66,35 @@ public class RequestLogTest
     @BeforeEach
     public void before() throws Exception
     {
-        _log = new Exchanger<String>();
+        _log = new Log();
         _server = new Server();
         _connector = new LocalConnector(_server);
         _server.addConnector(_connector);
-        _server.setRequestLog(new Log());
+        
+    }
+    
+    void testHandlerServerStart() throws Exception
+    {
+        _server.setRequestLog(_log);
         _server.setHandler(new TestHandler());
         _server.start();
     }
     
+    private void startServer() throws Exception
+    {
+        _server.start();
+    }
+
+    private void makeRequest(String requestPath) throws Exception
+    {
+        _connector.getResponse("GET "+requestPath+" HTTP/1.0\r\n\r\n");
+    }
+
+
+
     @AfterEach
     public void after() throws Exception
     {
-
         _server.stop();
     }
     
@@ -70,35 +102,41 @@ public class RequestLogTest
     @Test
     public void testNotHandled() throws Exception
     {
+        testHandlerServerStart();
+        
         _connector.getResponse("GET /foo HTTP/1.0\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET /foo HTTP/1.0\" 404 "));
     }
 
     @Test
     public void testRequestLine() throws Exception
     {
+        testHandlerServerStart();
+        
         _connector.getResponse("GET /foo?data=1 HTTP/1.0\nhost: host:80\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET /foo?data=1 HTTP/1.0\" 200 "));
         
         _connector.getResponse("GET //bad/foo?data=1 HTTP/1.0\n\n");
-        log = _log.exchange(null,5,TimeUnit.SECONDS);
+        log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET //bad/foo?data=1 HTTP/1.0\" 200 "));
                 
         _connector.getResponse("GET http://host:80/foo?data=1 HTTP/1.0\n\n");
-        log = _log.exchange(null,5,TimeUnit.SECONDS);
+        log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET http://host:80/foo?data=1 HTTP/1.0\" 200 "));   
     }
     
     @Test
     public void testHTTP10Host() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse(
             "GET /foo?name=value HTTP/1.0\n"+
             "Host: servername\n"+
             "\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET /foo?name=value"));
         assertThat(log,containsString(" 200 "));
     }
@@ -106,11 +144,13 @@ public class RequestLogTest
     @Test
     public void testHTTP11() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse(
             "GET /foo?name=value HTTP/1.1\n"+
             "Host: servername\n"+
             "\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET /foo?name=value"));
         assertThat(log,containsString(" 200 "));
     }
@@ -118,11 +158,13 @@ public class RequestLogTest
     @Test
     public void testAbsolute() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse(
             "GET http://hostname:8888/foo?name=value HTTP/1.1\n"+
             "Host: servername\n"+
             "\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET http://hostname:8888/foo?name=value"));
         assertThat(log,containsString(" 200 "));
     }
@@ -130,8 +172,10 @@ public class RequestLogTest
     @Test
     public void testQuery() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("GET /foo?name=value HTTP/1.0\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET /foo?name=value"));
         assertThat(log,containsString(" 200 "));
     }
@@ -139,8 +183,10 @@ public class RequestLogTest
     @Test
     public void testSmallData() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("GET /foo?data=42 HTTP/1.0\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET /foo?"));
         assertThat(log,containsString(" 200 42 "));
     }
@@ -148,8 +194,10 @@ public class RequestLogTest
     @Test
     public void testBigData() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("GET /foo?data=102400 HTTP/1.0\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET /foo?"));
         assertThat(log,containsString(" 200 102400 "));
     }
@@ -157,8 +205,10 @@ public class RequestLogTest
     @Test
     public void testStatus() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("GET /foo?status=206 HTTP/1.0\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET /foo?"));
         assertThat(log,containsString(" 206 0 "));
     }
@@ -166,8 +216,10 @@ public class RequestLogTest
     @Test
     public void testStatusData() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("GET /foo?status=206&data=42 HTTP/1.0\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET /foo?"));
         assertThat(log,containsString(" 206 42 "));
     }
@@ -175,83 +227,460 @@ public class RequestLogTest
     @Test
     public void testBadRequest() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("XXXXXXXXXXXX\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("\"- - -\""));
-        assertThat(log,containsString(" 400 0 "));
+        assertThat(log,containsString(" 400 "));
     }
     
     @Test
     public void testBadCharacter() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("METHOD /f\00o HTTP/1.0\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("\"- - -\""));
-        assertThat(log,containsString(" 400 0 "));
+        assertThat(log,containsString(" 400 "));
     }
     
     @Test
     public void testBadVersion() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("METHOD /foo HTTP/9\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("\"- - -\""));
-        assertThat(log,containsString(" 400 0 "));
+        assertThat(log,containsString(" 400 "));
     }
     
     @Test
     public void testLongURI() throws Exception
     {
+        testHandlerServerStart();
+
         char[] chars = new char[10000];
         Arrays.fill(chars,'o');
         String ooo = new String(chars);
         _connector.getResponse("METHOD /f"+ooo+" HTTP/1.0\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("\"- - -\""));
-        assertThat(log,containsString(" 414 0 "));
+        assertThat(log,containsString(" 414 "));
     }
     
     @Test
     public void testLongHeader() throws Exception
     {
+        testHandlerServerStart();
+
         char[] chars = new char[10000];
         Arrays.fill(chars,'o');
         String ooo = new String(chars);
         _connector.getResponse("METHOD /foo HTTP/1.0\name: f+"+ooo+"\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("\"METHOD /foo HTTP/1.0\""));
-        assertThat(log,containsString(" 431 0 "));
+        assertThat(log,containsString(" 431 "));
     }
     
     @Test
     public void testBadRequestNoHost() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("GET /foo HTTP/1.1\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET /foo "));
-        assertThat(log,containsString(" 400 0 "));
+        assertThat(log,containsString(" 400 "));
     }
 
     @Test
     public void testUseragentWithout() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("GET http://[:1]/foo HTTP/1.1\nReferer: http://other.site\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET http://[:1]/foo "));
-        assertThat(log,containsString(" 400 0 \"http://other.site\" \"-\" - "));
+        assertThat(log,containsString(" 400 50 \"http://other.site\" \"-\" - "));
     }
 
     @Test
     public void testUseragentWith() throws Exception
     {
+        testHandlerServerStart();
+
         _connector.getResponse("GET http://[:1]/foo HTTP/1.1\nReferer: http://other.site\nUser-Agent: Mozilla/5.0 (test)\n\n");
-        String log = _log.exchange(null,5,TimeUnit.SECONDS);
+        String log = _log.entries.poll(5,TimeUnit.SECONDS);
         assertThat(log,containsString("GET http://[:1]/foo "));
-        assertThat(log,containsString(" 400 0 \"http://other.site\" \"Mozilla/5.0 (test)\" - "));
+        assertThat(log,containsString(" 400 50 \"http://other.site\" \"Mozilla/5.0 (test)\" - "));
     }
+    
+
+    // Tests from here use these parameters
+    public static Stream<Arguments> data()
+    {
+        List<Object[]> data = new ArrayList<>();
+
+        data.add(new Object[] { new NoopHandler(), "/noop", "\"GET /noop HTTP/1.0\" 404" });
+        data.add(new Object[] { new HelloHandler(), "/hello", "\"GET /hello HTTP/1.0\" 200" });
+        data.add(new Object[] { new ResponseSendErrorHandler(), "/sendError", "\"GET /sendError HTTP/1.0\" 599" });
+        data.add(new Object[] { new ServletExceptionHandler(), "/sex", "\"GET /sex HTTP/1.0\" 500" });
+        data.add(new Object[] { new IOExceptionHandler(), "/ioex", "\"GET /ioex HTTP/1.0\" 500" });
+        data.add(new Object[] { new RuntimeExceptionHandler(), "/rtex", "\"GET /rtex HTTP/1.0\" 500" });
+        data.add(new Object[] { new BadMessageHandler(), "/bad", "\"GET /bad HTTP/1.0\" 499" });
+        data.add(new Object[] { new AbortHandler(), "/bad", "\"GET /bad HTTP/1.0\" 488" });
+
+        return data.stream().map(Arguments::of);
+    }
+
+    @ParameterizedTest
+    @MethodSource("data")
+    public void testServerRequestLog(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
+    {
+        _server.setRequestLog(_log);
+        _server.setHandler(testHandler);
+        startServer();
+        makeRequest(requestPath);
+        assertRequestLog(expectedLogEntry, _log);
+    }
+
+    @ParameterizedTest
+    @MethodSource("data")
+    public void testLogHandlerWrapper(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
+    {
+        RequestLogHandler handler = new RequestLogHandler();
+        handler.setRequestLog(_log);
+        handler.setHandler(testHandler);
+        _server.setHandler(handler);
+        startServer();
+        makeRequest(requestPath);
+        assertRequestLog(expectedLogEntry, _log);
+    }
+
+    @ParameterizedTest
+    @MethodSource("data")
+    public void testLogHandlerCollectionFirst(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
+    {
+        RequestLogHandler handler = new RequestLogHandler();
+        handler.setRequestLog(_log);
+        HandlerCollection handlers = new HandlerCollection();
+        handlers.setHandlers(new Handler[] { handler, testHandler });
+        _server.setHandler(handlers);
+        startServer();
+        makeRequest(requestPath);
+        assertRequestLog(expectedLogEntry, _log);
+    }
+
+
+    @ParameterizedTest
+    @MethodSource("data")
+    public void testLogHandlerCollectionLast(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
+    {
+        RequestLogHandler handler = new RequestLogHandler();
+        handler.setRequestLog(_log);
+        // This is the old ordering of request handler and it cannot well handle thrown exception
+        Assumptions.assumeTrue(
+            testHandler instanceof NoopHandler ||
+                testHandler instanceof HelloHandler ||
+                testHandler instanceof ResponseSendErrorHandler
+        );
+
+        HandlerCollection handlers = new HandlerCollection();
+        handlers.setHandlers(new Handler[] { testHandler, handler });
+        _server.setHandler(handlers);
+        startServer();
+        makeRequest(requestPath);
+        assertRequestLog(expectedLogEntry, _log);
+    }
+
+
+    @ParameterizedTest
+    @MethodSource("data")
+    public void testErrorHandler(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
+    {
+        _server.setRequestLog(_log);
+        AbstractHandler.ErrorDispatchHandler wrapper = new AbstractHandler.ErrorDispatchHandler()
+        {
+            @Override
+            protected void doNonErrorHandle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response)
+                throws IOException, ServletException
+            {
+                testHandler.handle(target,baseRequest,request,response);
+            }
+        };
+
+        _server.setHandler(wrapper);
+
+        List<String> errors = new ArrayList<>();
+        ErrorHandler errorHandler = new ErrorHandler()
+        {
+            @Override
+            public void doError(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException
+            {
+                errors.add(baseRequest.getRequestURI());
+                super.doError(target, baseRequest, request, response);
+            }
+        };
+        _server.addBean(errorHandler);
+        startServer();
+        makeRequest(requestPath);
+        assertRequestLog(expectedLogEntry, _log);
+
+        if (!(testHandler instanceof HelloHandler))
+            assertThat(errors,contains(requestPath));
+    }
+
+
+    @ParameterizedTest
+    @MethodSource("data")
+    public void testOKErrorHandler(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
+    {
+        _server.setRequestLog(_log);
+        AbstractHandler.ErrorDispatchHandler wrapper = new AbstractHandler.ErrorDispatchHandler()
+        {
+            @Override
+            protected void doNonErrorHandle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response)
+                throws IOException, ServletException
+            {
+                testHandler.handle(target,baseRequest,request,response);
+            }
+        };
+
+        _server.setHandler(wrapper);
+
+        ErrorHandler errorHandler = new OKErrorHandler();
+        _server.addBean(errorHandler);
+        startServer();
+        makeRequest(requestPath);
+
+        expectedLogEntry = "\"GET " + requestPath + " HTTP/1.0\" 200";
+        assertRequestLog(expectedLogEntry, _log);
+    }
+
+
+    @ParameterizedTest
+    @MethodSource("data")
+    public void testAsyncDispatch(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
+    {
+        _server.setRequestLog(_log);
+        _server.setHandler(new AbstractHandler()
+        {
+            @Override
+            public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response)
+                throws IOException, ServletException
+            {
+                if (Boolean.TRUE.equals(request.getAttribute("ASYNC")))
+                    testHandler.handle(target,baseRequest,request,response);
+                else
+                {
+                    request.setAttribute("ASYNC",Boolean.TRUE);
+                    AsyncContext ac = request.startAsync();
+                    ac.setTimeout(1000);
+                    ac.dispatch();
+                    baseRequest.setHandled(true);
+                }
+            }
+        });
+        startServer();
+        makeRequest(requestPath);
+
+        assertRequestLog(expectedLogEntry, _log);
+    }
+
+
+    @ParameterizedTest
+    @MethodSource("data")
+    public void testAsyncComplete(Handler testHandler, String requestPath, String expectedLogEntry) throws Exception
+    {
+        _server.setRequestLog(_log);
+        _server.setHandler(new AbstractHandler()
+        {
+            @Override
+            public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response)
+                throws IOException, ServletException
+            {
+                if (Boolean.TRUE.equals(request.getAttribute("ASYNC")))
+                    testHandler.handle(target,baseRequest,request,response);
+                else
+                {
+                    request.setAttribute("ASYNC",Boolean.TRUE);
+                    AsyncContext ac = request.startAsync();
+                    ac.setTimeout(1000);
+                    baseRequest.setHandled(true);
+                    _server.getThreadPool().execute(()->
+                    {
+                        try
+                        {
+                            try
+                            {
+                                baseRequest.setHandled(false);
+                                testHandler.handle(target, baseRequest, request, response);
+                                if (!baseRequest.isHandled())
+                                    response.sendError(404);
+                            }
+                            catch (BadMessageException bad)
+                            {
+                                response.sendError(bad.getCode());
+                            }
+                            catch (Exception e)
+                            {
+                                response.sendError(500);
+                            }
+                        }
+                        catch(Throwable th)
+                        {
+                            throw new RuntimeException(th);
+                        }
+                        ac.complete();
+                    });
+                }
+            }
+        });
+        startServer();
+        makeRequest(requestPath);
+        assertRequestLog(expectedLogEntry, _log);
+    }
+
+
+    private void assertRequestLog(final String expectedLogEntry, Log log) throws Exception
+    {
+        String line = log.entries.poll(5, TimeUnit.SECONDS);
+        Assertions.assertNotNull(line);
+        assertThat(line,containsString(expectedLogEntry));
+        Assertions.assertTrue(log.entries.isEmpty());
+    }
+
+    public static class CaptureLog extends AbstractLifeCycle implements RequestLog
+    {
+        public BlockingQueue<String> log = new BlockingArrayQueue<>();
+
+        @Override
+        public void log(Request request, Response response)
+        {
+            int status = response.getCommittedMetaData().getStatus();
+            log.add(String.format("%s %s %s %03d",request.getMethod(),request.getRequestURI(),request.getProtocol(),status));
+        }
+    }
+
+    private static abstract class AbstractTestHandler extends AbstractHandler
+    {
+        @Override
+        public String toString()
+        {
+            return this.getClass().getSimpleName();
+        }
+    }
+
+    private static class NoopHandler extends AbstractTestHandler
+    {
+        @Override
+        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
+        {
+        }
+    }
+
+    private static class HelloHandler extends AbstractTestHandler
+    {
+        @Override
+        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
+        {
+            response.setContentType("text/plain");
+            response.getWriter().print("Hello World");
+            if (baseRequest!=null)
+                baseRequest.setHandled(true);
+        }
+    }
+
+    private static class ResponseSendErrorHandler extends AbstractTestHandler
+    {
+        @Override
+        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
+        {
+            response.sendError(599,"expected");
+            if (baseRequest!=null)
+                baseRequest.setHandled(true);
+        }
+    }
+
+    private static class ServletExceptionHandler extends AbstractTestHandler
+    {
+        @Override
+        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
+        {
+            throw new ServletException("expected");
+        }
+    }
+
+    private static class IOExceptionHandler extends AbstractTestHandler
+    {
+        @Override
+        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
+        {
+            throw new IOException("expected");
+        }
+    }
+
+    private static class RuntimeExceptionHandler extends AbstractTestHandler
+    {
+        @Override
+        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
+        {
+            throw new RuntimeException("expected");
+        }
+    }
+
+    private static class BadMessageHandler extends AbstractTestHandler
+    {
+        @Override
+        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
+        {
+            throw new BadMessageException(499);
+        }
+    }
+
+    private static class AbortHandler extends AbstractTestHandler
+    {
+        @Override
+        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
+        {
+            BadMessageException bad = new BadMessageException(488);
+            baseRequest.getHttpChannel().abort(bad);
+            throw bad;
+        }
+    }
+
+    public static class OKErrorHandler extends ErrorHandler
+    {
+        @Override
+        public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException
+        {
+            if (baseRequest.isHandled() || response.isCommitted())
+            {
+                return;
+            }
+
+            // collect error details
+            String reason = (response instanceof Response)?((Response)response).getReason():null;
+            int status = response.getStatus();
+
+            // intentionally set response status to OK (this is a test to see what is actually logged)
+            response.setStatus(200);
+            response.setContentType("text/plain");
+            PrintWriter out = response.getWriter();
+            out.printf("Error %d: %s%n",status,reason);
+            baseRequest.setHandled(true);
+        }
+    }
+
 
     private class Log extends AbstractNCSARequestLog
     {
+        public BlockingQueue<String> entries = new BlockingArrayQueue<>();
+
+        Log()
         {
             super.setExtended(true);
             super.setLogLatency(true);
@@ -269,7 +698,7 @@ public class RequestLogTest
         {
             try
             {
-                _log.exchange(requestEntry);
+                entries.add(requestEntry);
             }
             catch(Exception e)
             {
@@ -277,7 +706,7 @@ public class RequestLogTest
             }
         }
     }
-    
+
     private class TestHandler extends AbstractHandler
     {
         @Override
@@ -286,7 +715,7 @@ public class RequestLogTest
             String q = request.getQueryString();
             if (q==null)
                 return;
-            
+
             baseRequest.setHandled(true);
             for (String action : q.split("\\&"))
             {
@@ -300,12 +729,12 @@ public class RequestLogTest
                         response.setStatus(Integer.parseInt(value));
                         break;
                     }
-                        
+
                     case "data":
                     {
                         int data = Integer.parseInt(value);
                         PrintWriter out = response.getWriter();
-                        
+
                         int w=0;
                         while (w<data)
                         {
@@ -343,7 +772,7 @@ public class RequestLogTest
                         response.flushBuffer();
                         break;
                     }
-                    
+
                     case "read":
                     {
                         InputStream in = request.getInputStream();

jetty-servlet/src/test/java/org/eclipse/jetty/servlet/AsyncServletTest.java

@@ -53,14 +53,12 @@ import javax.servlet.http.HttpServletResponseWrapper;
 import org.eclipse.jetty.server.Connector;
 import org.eclipse.jetty.server.DebugListener;
 import org.eclipse.jetty.server.HttpChannel;
-import org.eclipse.jetty.server.HttpChannel.Listener;
 import org.eclipse.jetty.server.QuietServletException;
 import org.eclipse.jetty.server.Request;
 import org.eclipse.jetty.server.RequestLog;
 import org.eclipse.jetty.server.Response;
 import org.eclipse.jetty.server.Server;
 import org.eclipse.jetty.server.ServerConnector;
-import org.eclipse.jetty.server.handler.RequestLogHandler;
 import org.eclipse.jetty.util.IO;
 import org.eclipse.jetty.util.URIUtil;
 import org.eclipse.jetty.util.component.AbstractLifeCycle;
@@ -99,15 +97,13 @@ public class AsyncServletTest
 
         _log=new ArrayList<>();
         RequestLog log=new Log();
-        RequestLogHandler logHandler = new RequestLogHandler();
+        _server.setRequestLog(log);
-        logHandler.setRequestLog(log);
-        _server.setHandler(logHandler);
         _expectedLogs=1;
         _expectedCode="200 ";
 
         ServletContextHandler context = new ServletContextHandler(ServletContextHandler.NO_SESSIONS);
         context.setContextPath("/ctx");
-        logHandler.setHandler(context);
+        _server.setHandler(context);
         context.addEventListener(new DebugListener());
         
         _errorHandler = new ErrorPageErrorHandler();

jetty-servlet/src/test/java/org/eclipse/jetty/servlet/ServletRequestLogTest.java

@@ -53,7 +53,6 @@ import org.eclipse.jetty.server.handler.ContextHandlerCollection;
 import org.eclipse.jetty.server.handler.DefaultHandler;
 import org.eclipse.jetty.server.handler.ErrorHandler;
 import org.eclipse.jetty.server.handler.HandlerCollection;
-import org.eclipse.jetty.server.handler.RequestLogHandler;
 import org.eclipse.jetty.toolchain.test.IO;
 import org.eclipse.jetty.util.component.AbstractLifeCycle;
 import org.eclipse.jetty.util.log.Log;
@@ -313,12 +312,9 @@ public class ServletRequestLogTest
 
         // Next the behavior as defined by etc/jetty-requestlog.xml
         // the id="RequestLog"
-        RequestLogHandler requestLog = new RequestLogHandler();
         CaptureLog captureLog = new CaptureLog();
-        requestLog.setRequestLog(captureLog);
+        server.setRequestLog(captureLog);
 
-        handlers.addHandler(requestLog);
-        
         // Lastly, the behavior as defined by deployment of a webapp
         // Add the Servlet Context
         ServletContextHandler app = new ServletContextHandler(ServletContextHandler.SESSIONS);
@@ -404,12 +400,9 @@ public class ServletRequestLogTest
 
         // Next the behavior as defined by etc/jetty-requestlog.xml
         // the id="RequestLog"
-        RequestLogHandler requestLog = new RequestLogHandler();
         CaptureLog captureLog = new CaptureLog();
-        requestLog.setRequestLog(captureLog);
+        server.setRequestLog(captureLog);
 
-        handlers.addHandler(requestLog);
-        
         // Lastly, the behavior as defined by deployment of a webapp
         // Add the Servlet Context
         ServletContextHandler app = new ServletContextHandler(ServletContextHandler.SESSIONS);
@@ -493,12 +486,9 @@ public class ServletRequestLogTest
 
         // Next the behavior as defined by etc/jetty-requestlog.xml
         // the id="RequestLog"
-        RequestLogHandler requestLog = new RequestLogHandler();
         CaptureLog captureLog = new CaptureLog();
-        requestLog.setRequestLog(captureLog);
+        server.setRequestLog(captureLog);
 
-        handlers.addHandler(requestLog);
-        
         // Lastly, the behavior as defined by deployment of a webapp
         // Add the Servlet Context
         ServletContextHandler app = new ServletContextHandler(ServletContextHandler.SESSIONS);
@@ -587,14 +577,9 @@ public class ServletRequestLogTest
 
         // Next the proposed behavioral change to etc/jetty-requestlog.xml
         // the id="RequestLog"
-        RequestLogHandler requestLog = new RequestLogHandler();
         CaptureLog captureLog = new CaptureLog();
-        requestLog.setRequestLog(captureLog);
+        server.setRequestLog(captureLog);
-        
+
-        Handler origServerHandler = server.getHandler();
-        requestLog.setHandler(origServerHandler);
-        server.setHandler(requestLog);
-        
         // Lastly, the behavior as defined by deployment of a webapp
         // Add the Servlet Context
         ServletContextHandler app = new ServletContextHandler(ServletContextHandler.SESSIONS);

tests/test-http-client-transport/src/test/java/org/eclipse/jetty/http/client/ServerTimeoutsTest.java

@@ -20,9 +20,14 @@ package org.eclipse.jetty.http.client;
 
 import static org.eclipse.jetty.http.client.Transport.FCGI;
 import static org.eclipse.jetty.http.client.Transport.UNIX_SOCKET;
+import static org.hamcrest.Matchers.containsString;
+import static org.hamcrest.Matchers.instanceOf;
+import static org.hamcrest.Matchers.is;
+import static org.junit.Assert.assertThat;
 import static org.junit.jupiter.api.Assertions.assertArrayEquals;
 import static org.junit.jupiter.api.Assertions.assertEquals;
 import static org.junit.jupiter.api.Assertions.assertFalse;
+import static org.junit.jupiter.api.Assertions.assertNotNull;
 import static org.junit.jupiter.api.Assertions.assertTrue;
 
 import java.io.IOException;
@@ -56,10 +61,10 @@ import org.eclipse.jetty.server.Handler;
 import org.eclipse.jetty.server.HttpChannel;
 import org.eclipse.jetty.server.Request;
 import org.eclipse.jetty.server.handler.AbstractHandler;
+import org.eclipse.jetty.util.BlockingArrayQueue;
 import org.eclipse.jetty.util.Callback;
 import org.eclipse.jetty.util.IO;
 import org.eclipse.jetty.util.log.StacklessLogging;
-import org.eclipse.jetty.util.thread.QueuedThreadPool;
 import org.junit.jupiter.api.Assumptions;
 import org.junit.jupiter.params.ParameterizedTest;
 import org.junit.jupiter.params.provider.ArgumentsSource;
@@ -616,6 +621,7 @@ public class ServerTimeoutsTest extends AbstractTest<TransportScenario>
     {
         init(transport);
         int bytesPerSecond = 20;
+        scenario.requestLog.clear();
         scenario.httpConfig.setMinRequestDataRate(bytesPerSecond);
         CountDownLatch handlerLatch = new CountDownLatch(1);
         scenario.start(new AbstractHandler.ErrorDispatchHandler()
@@ -643,13 +649,15 @@ public class ServerTimeoutsTest extends AbstractTest<TransportScenario>
         });
 
         DeferredContentProvider contentProvider = new DeferredContentProvider();
-        CountDownLatch resultLatch = new CountDownLatch(1);
+        BlockingQueue<Object> results = new BlockingArrayQueue<>();
         scenario.client.newRequest(scenario.newURI())
                 .content(contentProvider)
                 .send(result ->
                 {
-                    if (result.getResponse().getStatus() == HttpStatus.REQUEST_TIMEOUT_408)
+                    if (result.isFailed())
-                        resultLatch.countDown();
+                        results.offer(result.getFailure());
+                    else
+                        results.offer(result.getResponse().getStatus());
                 });
 
         for (int i = 0; i < 3; ++i)
@@ -659,9 +667,17 @@ public class ServerTimeoutsTest extends AbstractTest<TransportScenario>
         }
         contentProvider.close();
 
+        assertThat(scenario.requestLog.poll(5,TimeUnit.SECONDS), containsString(" 408"));
+
         // Request should timeout.
         assertTrue(handlerLatch.await(5, TimeUnit.SECONDS));
-        assertTrue(resultLatch.await(5, TimeUnit.SECONDS));
+
+        Object result = results.poll(5, TimeUnit.SECONDS);
+        assertNotNull(result);
+        if (result instanceof Integer)
+            assertThat((Integer)result,is(408));
+        else
+            assertThat(result,instanceOf(Throwable.class));
     }
 
     @ParameterizedTest

tests/test-http-client-transport/src/test/java/org/eclipse/jetty/http/client/TransportScenario.java

@@ -25,6 +25,7 @@ import java.nio.file.Path;
 import java.util.ArrayList;
 import java.util.List;
 import java.util.Optional;
+import java.util.concurrent.BlockingQueue;
 
 import javax.servlet.http.HttpServlet;
 
@@ -56,6 +57,7 @@ import org.eclipse.jetty.servlet.ServletHolder;
 import org.eclipse.jetty.toolchain.test.MavenTestingUtils;
 import org.eclipse.jetty.unixsocket.UnixSocketConnector;
 import org.eclipse.jetty.unixsocket.client.HttpClientTransportOverUnixSockets;
+import org.eclipse.jetty.util.BlockingArrayQueue;
 import org.eclipse.jetty.util.SocketAddressResolver;
 import org.eclipse.jetty.util.log.Log;
 import org.eclipse.jetty.util.log.Logger;
@@ -75,6 +77,7 @@ public class TransportScenario
     protected String servletPath = "/servlet";
     protected HttpClient client;
     protected Path sockFile;
+    protected final BlockingQueue<String> requestLog= new BlockingArrayQueue<>();
 
     public TransportScenario(final Transport transport) throws IOException
     {
@@ -320,7 +323,15 @@ public class TransportScenario
         server.addBean(mbeanContainer);
         connector = newServerConnector(server);
         server.addConnector(connector);
+
+        server.setRequestLog((request, response) ->
+        {
+            int status = response.getCommittedMetaData().getStatus();
+            requestLog.offer(String.format("%s %s %s %03d",request.getMethod(),request.getRequestURI(),request.getProtocol(),status));
+        });
+
         server.setHandler(handler);
+
         try
         {
             server.start();
@@ -375,4 +386,6 @@ public class TransportScenario
             }
         }
     }
+
+
 }

tests/test-webapps/test-jetty-webapp/src/test/java/org/eclipse/jetty/TestServer.java

@@ -34,7 +34,6 @@ import org.eclipse.jetty.server.handler.ContextHandlerCollection;
 import org.eclipse.jetty.server.handler.DefaultHandler;
 import org.eclipse.jetty.server.handler.HandlerCollection;
 import org.eclipse.jetty.server.handler.HandlerWrapper;
-import org.eclipse.jetty.server.handler.RequestLogHandler;
 import org.eclipse.jetty.server.handler.ResourceHandler;
 import org.eclipse.jetty.server.session.DefaultSessionCache;
 import org.eclipse.jetty.server.session.FileSessionDataStore;
@@ -105,9 +104,8 @@ public class TestServer
         // Handlers
         HandlerCollection handlers = new HandlerCollection();
         ContextHandlerCollection contexts = new ContextHandlerCollection();
-        RequestLogHandler requestLogHandler = new RequestLogHandler();
         handlers.setHandlers(new Handler[]
-        { contexts, new DefaultHandler(), requestLogHandler });
+        { contexts, new DefaultHandler() });
 
         // Add restart handler to test the ability to save sessions and restart
         RestartHandler restart = new RestartHandler();
@@ -125,7 +123,7 @@ public class TestServer
         File log=File.createTempFile("jetty-yyyy_mm_dd", "log");
         NCSARequestLog requestLog = new NCSARequestLog(log.toString());
         requestLog.setExtended(false);
-        requestLogHandler.setRequestLog(requestLog);
+        server.setRequestLog(requestLog);
 
         server.setStopAtShutdown(true);