Fix racy HTTP tests by waiting for requests to finish

Ensure the background Jetty threads have been able to write the
request log record before the JUnit thread tries to read the set
of requests back.  This wait is necessary because the JUnit thread
may be able to continue as soon as Jetty has finished writing
the response onto the socket, and hasn't necessarily finished the
post-response logging activity.

By using a semaphore with a fixed number of resources, and using
one resource per request, but all of them when we want to read the
log, we implement a simple lock that requires there be no active
requests when we want to get the log from the JUnit thread.

Change-Id: I499e1c96418557185d0e19ba8befe892f26ce7e4
Signed-off-by: Shawn O. Pearce <spearce@spearce.org>

2 files changed, 87 insertions, 26 deletions

diff --git a/org.eclipse.jgit.http.test/tst/org/eclipse/jgit/http/test/util/AppServer.java b/org.eclipse.jgit.http.test/tst/org/eclipse/jgit/http/test/util/AppServer.java
index 74df7086ea..6e357f18b5 100644
--- a/org.eclipse.jgit.http.test/tst/org/eclipse/jgit/http/test/util/AppServer.java
+++ b/org.eclipse.jgit.http.test/tst/org/eclipse/jgit/http/test/util/AppServer.java
@@ -64,7 +64,6 @@ import org.eclipse.jetty.server.Connector;
 import org.eclipse.jetty.server.Server;
 import org.eclipse.jetty.server.UserIdentity;
 import org.eclipse.jetty.server.handler.ContextHandlerCollection;
-import org.eclipse.jetty.server.handler.RequestLogHandler;
 import org.eclipse.jetty.server.nio.SelectChannelConnector;
 import org.eclipse.jetty.servlet.ServletContextHandler;
 import org.eclipse.jetty.util.thread.QueuedThreadPool;
@@ -126,15 +125,12 @@ public class AppServer {
 		contexts = new ContextHandlerCollection();
 
 		log = new TestRequestLog();
-
-		final RequestLogHandler logHandler = new RequestLogHandler();
-		logHandler.setHandler(contexts);
-		logHandler.setRequestLog(log);
+		log.setHandler(contexts);
 
 		server = new Server();
 		server.setConnectors(new Connector[] { connector });
 		server.setThreadPool(pool);
-		server.setHandler(logHandler);
+		server.setHandler(log);
 
 		server.setStopAtShutdown(false);
 		server.setGracefulShutdown(0);
diff --git a/org.eclipse.jgit.http.test/tst/org/eclipse/jgit/http/test/util/TestRequestLog.java b/org.eclipse.jgit.http.test/tst/org/eclipse/jgit/http/test/util/TestRequestLog.java
index 904f6aac8e..6d3341bf62 100644
--- a/org.eclipse.jgit.http.test/tst/org/eclipse/jgit/http/test/util/TestRequestLog.java
+++ b/org.eclipse.jgit.http.test/tst/org/eclipse/jgit/http/test/util/TestRequestLog.java
@@ -43,29 +43,94 @@
 
 package org.eclipse.jgit.http.test.util;
 
+import org.eclipse.jetty.server.DispatcherType;
+import org.eclipse.jetty.server.Request;
+import org.eclipse.jetty.server.Response;
+import org.eclipse.jetty.server.handler.HandlerWrapper;
+
+import java.io.IOException;
 import java.util.ArrayList;
 import java.util.List;
+import java.util.concurrent.Semaphore;
 
-import org.eclipse.jetty.server.Request;
-import org.eclipse.jetty.server.RequestLog;
-import org.eclipse.jetty.server.Response;
-import org.eclipse.jetty.util.component.AbstractLifeCycle;
+import javax.servlet.ServletException;
+import javax.servlet.http.HttpServletRequest;
+import javax.servlet.http.HttpServletResponse;
 
 /** Logs request made through {@link AppServer}. */
-class TestRequestLog extends AbstractLifeCycle implements RequestLog {
-	private final List<AccessEvent> events = new ArrayList<AccessEvent>();
-
-	/** Reset the log back to its original empty state. */
-	synchronized void clear() {
-		events.clear();
-	}
-
-	/** @return all of the events made since the last clear. */
-	synchronized List<AccessEvent> getEvents() {
-		return events;
-	}
-
-	public synchronized void log(Request request, Response response) {
-		events.add(new AccessEvent(request, response));
-	}
+class TestRequestLog extends HandlerWrapper {
+  private static final int MAX = 16;
+
+  private final List<AccessEvent> events = new ArrayList<AccessEvent>();
+
+  private final Semaphore active = new Semaphore(MAX);
+
+  /** Reset the log back to its original empty state. */
+  void clear() {
+    try {
+      for (;;) {
+        try {
+          active.acquire(MAX);
+          break;
+        } catch (InterruptedException e) {
+          continue;
+        }
+      }
+
+      synchronized (events) {
+        events.clear();
+      }
+    } finally {
+      active.release(MAX);
+    }
+  }
+
+  /** @return all of the events made since the last clear. */
+  List<AccessEvent> getEvents() {
+    try {
+      for (;;) {
+        try {
+          active.acquire(MAX);
+          break;
+        } catch (InterruptedException e) {
+          continue;
+        }
+      }
+
+      synchronized (events) {
+        return events;
+      }
+    } finally {
+      active.release(MAX);
+    }
+  }
+
+  @Override
+  public void handle(String target, Request baseRequest, HttpServletRequest request,
+      HttpServletResponse response) throws IOException, ServletException {
+    try {
+      for (;;) {
+        try {
+          active.acquire();
+          break;
+        } catch (InterruptedException e) {
+          continue;
+        }
+      }
+
+      super.handle(target, baseRequest, request, response);
+
+      if (DispatcherType.REQUEST.equals(baseRequest.getDispatcherType()))
+        log((Request) request, (Response) response);
+
+    } finally {
+      active.release();
+    }
+  }
+
+  private void log(Request request, Response response) {
+    synchronized (events) {
+      events.add(new AccessEvent(request, response));
+    }
+  }
 }