From fe4b9cf366194e8b34ab54df8c31974bc9a582c2 Mon Sep 17 00:00:00 2001 From: Greg Wilkins Date: Wed, 13 Nov 2019 11:02:12 +1100 Subject: [PATCH] Issue #4161 Write LifeCycleViolation (#4294) * Issue #4161 - TestCase that can replicate problem on OSX Signed-off-by: Joakim Erdfelt * Issue #4161 - Naming Server threadpool (to help with debugging) Signed-off-by: Joakim Erdfelt * Issue #4161 - bumping up test file size to 10 MB Signed-off-by: Joakim Erdfelt * Issue #4161 Write LifeCycleViolation Do not callback on write completion until after state has been changed and notifications made. Signed-off-by: Greg Wilkins * Issue #4161 Write LifeCycleViolation Added a unit test that replicated the problem. Signed-off-by: Greg Wilkins * Issue #4161 - `EofException: request lifecycle violation` in stderr. Moved notifications of commit and content listeners back to succeeded(). Signed-off-by: Simone Bordet * Issue #4161 - Improved Logging for test-integration Signed-off-by: Joakim Erdfelt * Issue #4161 - Reducing size of test file Signed-off-by: Joakim Erdfelt --- .../org/eclipse/jetty/server/HttpChannel.java | 7 +- .../jetty/server/DelayedServerTest.java | 112 +++++++++ .../jetty/server/ExtendedServerTest.java | 6 - .../jetty/server/HttpServerTestBase.java | 53 ++++ tests/test-integration/pom.xml | 11 +- .../PersistentFileUploadDownloadTest.java | 231 ++++++++++++++++++ .../test/resources/jetty-logging.properties | 3 +- .../src/test/resources/logback.xml | 19 ++ 8 files changed, 429 insertions(+), 13 deletions(-) create mode 100644 jetty-server/src/test/java/org/eclipse/jetty/server/DelayedServerTest.java create mode 100644 tests/test-integration/src/test/java/org/eclipse/jetty/test/PersistentFileUploadDownloadTest.java create mode 100644 tests/test-integration/src/test/resources/logback.xml diff --git a/jetty-server/src/main/java/org/eclipse/jetty/server/HttpChannel.java b/jetty-server/src/main/java/org/eclipse/jetty/server/HttpChannel.java index c8c922746e1..1f787a0356c 100644 --- a/jetty-server/src/main/java/org/eclipse/jetty/server/HttpChannel.java +++ b/jetty-server/src/main/java/org/eclipse/jetty/server/HttpChannel.java @@ -1190,15 +1190,16 @@ public class HttpChannel implements Runnable, HttpOutput.Interceptor public void succeeded() { _written += _length; - if (_complete) - _response.getHttpOutput().closed(); - super.succeeded(); if (_commit) _combinedListener.onResponseCommit(_request); if (_length > 0) _combinedListener.onResponseContent(_request, _content); if (_complete && _state.completeResponse()) + { + _response.getHttpOutput().closed(); _combinedListener.onResponseEnd(_request); + } + super.succeeded(); } @Override diff --git a/jetty-server/src/test/java/org/eclipse/jetty/server/DelayedServerTest.java b/jetty-server/src/test/java/org/eclipse/jetty/server/DelayedServerTest.java new file mode 100644 index 00000000000..69e1f642251 --- /dev/null +++ b/jetty-server/src/test/java/org/eclipse/jetty/server/DelayedServerTest.java @@ -0,0 +1,112 @@ +// +// ======================================================================== +// Copyright (c) 1995-2019 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; + +import java.nio.ByteBuffer; + +import org.eclipse.jetty.http.HttpCompliance; +import org.eclipse.jetty.http.MetaData; +import org.eclipse.jetty.io.Connection; +import org.eclipse.jetty.io.EndPoint; +import org.eclipse.jetty.util.Callback; +import org.eclipse.jetty.util.thread.ThreadPool; +import org.junit.jupiter.api.BeforeEach; + +/** + * Extended Server Tester. + */ +public class DelayedServerTest extends HttpServerTestBase +{ + @BeforeEach + public void init() throws Exception + { + startServer(new ServerConnector(_server, new HttpConnectionFactory() + { + @Override + public Connection newConnection(Connector connector, EndPoint endPoint) + { + return configure(new DelayedHttpConnection(getHttpConfiguration(), connector, endPoint), connector, endPoint); + } + })); + } + + private static class DelayedHttpConnection extends HttpConnection + { + public DelayedHttpConnection(HttpConfiguration config, Connector connector, EndPoint endPoint) + { + super(config, connector, endPoint, HttpCompliance.RFC7230_LEGACY, false); + } + + @Override + public void send(MetaData.Response info, boolean head, ByteBuffer content, boolean lastContent, Callback callback) + { + DelayedCallback delay = new DelayedCallback(callback, getServer().getThreadPool()); + super.send(info, head, content, lastContent, delay); + } + } + + private static class DelayedCallback extends Callback.Nested + { + final ThreadPool pool; + + public DelayedCallback(Callback callback, ThreadPool threadPool) + { + super(callback); + pool = threadPool; + } + + @Override + public void succeeded() + { + pool.execute(()-> + { + try + { + Thread.sleep(10); + } + catch (InterruptedException e) + { + } + finally + { + super.succeeded(); + } + }); + } + + @Override + public void failed(Throwable x) + { + pool.execute(()-> + { + try + { + Thread.sleep(20); + } + catch (InterruptedException e) + { + } + finally + { + super.failed(x); + } + }); + } + } +} diff --git a/jetty-server/src/test/java/org/eclipse/jetty/server/ExtendedServerTest.java b/jetty-server/src/test/java/org/eclipse/jetty/server/ExtendedServerTest.java index c0cf2c8b336..31e5de16003 100644 --- a/jetty-server/src/test/java/org/eclipse/jetty/server/ExtendedServerTest.java +++ b/jetty-server/src/test/java/org/eclipse/jetty/server/ExtendedServerTest.java @@ -21,7 +21,6 @@ package org.eclipse.jetty.server; import java.io.IOException; import java.io.OutputStream; import java.net.Socket; -import java.nio.channels.SelectableChannel; import java.nio.channels.SelectionKey; import java.nio.channels.SocketChannel; import java.nio.charset.StandardCharsets; @@ -74,11 +73,6 @@ public class ExtendedServerTest extends HttpServerTestBase { private volatile long _lastSelected; - public ExtendedEndPoint(SelectableChannel channel, ManagedSelector selector, SelectionKey key, Scheduler scheduler) - { - super(channel, selector, key, scheduler); - } - public ExtendedEndPoint(SocketChannel channel, ManagedSelector selector, SelectionKey key, Scheduler scheduler) { super(channel, selector, key, scheduler); diff --git a/jetty-server/src/test/java/org/eclipse/jetty/server/HttpServerTestBase.java b/jetty-server/src/test/java/org/eclipse/jetty/server/HttpServerTestBase.java index 4bda5549721..2584039a25f 100644 --- a/jetty-server/src/test/java/org/eclipse/jetty/server/HttpServerTestBase.java +++ b/jetty-server/src/test/java/org/eclipse/jetty/server/HttpServerTestBase.java @@ -28,10 +28,12 @@ import java.io.LineNumberReader; import java.io.OutputStream; import java.net.Socket; import java.net.URL; +import java.nio.ByteBuffer; import java.nio.charset.StandardCharsets; import java.util.Arrays; import java.util.concurrent.Exchanger; import java.util.concurrent.atomic.AtomicBoolean; +import javax.servlet.AsyncContext; import javax.servlet.ServletException; import javax.servlet.ServletInputStream; import javax.servlet.ServletOutputStream; @@ -42,6 +44,8 @@ import org.eclipse.jetty.http.HttpTester; import org.eclipse.jetty.io.EndPoint; import org.eclipse.jetty.io.EofException; import org.eclipse.jetty.server.handler.AbstractHandler; +import org.eclipse.jetty.util.BufferUtil; +import org.eclipse.jetty.util.Callback; import org.eclipse.jetty.util.IO; import org.eclipse.jetty.util.log.AbstractLogger; import org.eclipse.jetty.util.log.Log; @@ -1816,4 +1820,53 @@ public abstract class HttpServerTestBase extends HttpServerTestFixture assertThat(client.getInputStream().read(), is(-1)); } } + + @Test + public void testSendAsyncContent() throws Exception + { + int size = 64 * 1024; + configureServer(new SendAsyncContentHandler(size)); + + try (Socket client = newSocket(_serverURI.getHost(), _serverURI.getPort())) + { + OutputStream os = client.getOutputStream(); + os.write(("GET / HTTP/1.1\r\nHost: localhost\r\n\r\n").getBytes(StandardCharsets.ISO_8859_1)); + os.flush(); + + HttpTester.Response response = HttpTester.parseResponse(client.getInputStream()); + assertThat(response.getStatus(), is(200)); + assertThat(response.getContentBytes().length, is(size)); + + // Try again to check previous request completed OK + os.write(("GET / HTTP/1.1\r\nHost: localhost\r\n\r\n").getBytes(StandardCharsets.ISO_8859_1)); + os.flush(); + response = HttpTester.parseResponse(client.getInputStream()); + assertThat(response.getStatus(), is(200)); + assertThat(response.getContentBytes().length, is(size)); + } + } + + private class SendAsyncContentHandler extends AbstractHandler + { + final ByteBuffer content; + + public SendAsyncContentHandler(int size) + { + content = BufferUtil.allocate(size); + Arrays.fill(content.array(),0,size,(byte)'X'); + content.position(0); + content.limit(size); + } + + @Override + public void handle(String target, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException + { + baseRequest.setHandled(true); + response.setStatus(200); + response.setContentType("application/unknown"); + response.setContentLength(content.remaining()); + AsyncContext async = request.startAsync(); + ((HttpOutput)response.getOutputStream()).sendContent(content.slice(), Callback.from(async::complete)); + } + } } diff --git a/tests/test-integration/pom.xml b/tests/test-integration/pom.xml index 6c2aeb4d8f5..a34116251ad 100644 --- a/tests/test-integration/pom.xml +++ b/tests/test-integration/pom.xml @@ -30,11 +30,11 @@ copy-dependencies - org.eclipse.jetty.tests + org.eclipse.jetty.tests test war - true - true + true + true true ${project.build.directory}/webapps @@ -143,5 +143,10 @@ ${project.version} test + + ch.qos.logback + logback-classic + 1.2.3 + diff --git a/tests/test-integration/src/test/java/org/eclipse/jetty/test/PersistentFileUploadDownloadTest.java b/tests/test-integration/src/test/java/org/eclipse/jetty/test/PersistentFileUploadDownloadTest.java new file mode 100644 index 00000000000..b70f1f64cc1 --- /dev/null +++ b/tests/test-integration/src/test/java/org/eclipse/jetty/test/PersistentFileUploadDownloadTest.java @@ -0,0 +1,231 @@ +// +// ======================================================================== +// Copyright (c) 1995-2019 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.test; + +import java.io.BufferedWriter; +import java.io.IOException; +import java.io.InputStream; +import java.net.URI; +import java.nio.file.Files; +import java.nio.file.Path; +import java.util.concurrent.ExecutionException; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.TimeoutException; +import javax.servlet.http.HttpServletRequest; +import javax.servlet.http.HttpServletResponse; + +import org.eclipse.jetty.client.HttpClient; +import org.eclipse.jetty.client.api.ContentResponse; +import org.eclipse.jetty.client.api.Response; +import org.eclipse.jetty.client.util.InputStreamResponseListener; +import org.eclipse.jetty.http.HttpMethod; +import org.eclipse.jetty.server.HttpChannel; +import org.eclipse.jetty.server.Request; +import org.eclipse.jetty.server.Server; +import org.eclipse.jetty.server.ServerConnector; +import org.eclipse.jetty.servlet.DefaultServlet; +import org.eclipse.jetty.servlet.ServletContextHandler; +import org.eclipse.jetty.servlet.ServletHolder; +import org.eclipse.jetty.toolchain.test.FS; +import org.eclipse.jetty.toolchain.test.jupiter.WorkDir; +import org.eclipse.jetty.toolchain.test.jupiter.WorkDirExtension; +import org.eclipse.jetty.util.component.LifeCycle; +import org.eclipse.jetty.util.log.Log; +import org.eclipse.jetty.util.log.Logger; +import org.eclipse.jetty.util.resource.PathResource; +import org.eclipse.jetty.util.thread.QueuedThreadPool; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.ExtendWith; + +import static java.nio.charset.StandardCharsets.UTF_8; +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.is; + +@ExtendWith(WorkDirExtension.class) +public class PersistentFileUploadDownloadTest +{ + public static final Logger LOG = Log.getLogger(PersistentFileUploadDownloadTest.class); + public WorkDir workDir; + + private Server server; + private HttpClient client; + + @BeforeEach + public void startServerAndClient() throws Exception + { + QueuedThreadPool serverThreadPool = new QueuedThreadPool(); + serverThreadPool.setName("Server"); + server = new Server(serverThreadPool); + + ServerConnector connector = new ServerConnector(server); + connector.setPort(0); + connector.addBean(new ChannelLogger()); + server.addConnector(connector); + + ServletContextHandler contextHandler = new ServletContextHandler(); + + Path storageDir = workDir.getEmptyPathDir(); + contextHandler.setBaseResource(new PathResource(storageDir)); + + UploadDownloadServlet uploadDownloadServlet = new UploadDownloadServlet(storageDir); + ServletHolder uploadDownloadHolder = new ServletHolder(uploadDownloadServlet); + contextHandler.addServlet(uploadDownloadHolder, "/"); + server.setHandler(contextHandler); + + server.start(); + + QueuedThreadPool clientThreadPool = new QueuedThreadPool(); + clientThreadPool.setName("Client"); // so we can tell which threads belong to client + client = new HttpClient(); + client.setExecutor(clientThreadPool); + + client.start(); + } + + @AfterEach + public void stopServerAndClient() + { + LifeCycle.stop(client); + LifeCycle.stop(server); + } + + @Test + public void testMultipleUploadDownload() throws Exception + { + Path workBase = workDir.getPath().resolve("upload-download"); + FS.ensureEmpty(workBase); + Path uploadFile = workBase.resolve("upload-test-file.txt"); + Path downloadFile = workBase.resolve("download-test-file.txt"); + + createTestFile(uploadFile, "test-file-content", 100_000); + + int iterations = 100; + + for (int i = 0; i < iterations; i++) + { + URI uri = server.getURI().resolve("/upload-filename?iter=" + i); + + LOG.debug("---- Test Iteration {} -----", i); + + // Upload (PUT) File + clientPUT(uploadFile, uri); + + // Download (GET) File + clientGET(uri, downloadFile); + } + } + + private void clientGET(URI uri, Path localFile) throws InterruptedException, TimeoutException, ExecutionException, IOException + { + Files.deleteIfExists(localFile); + + InputStreamResponseListener listener = new InputStreamResponseListener(); + client.newRequest(uri).send(listener); + + Response response = listener.get(Long.MAX_VALUE, TimeUnit.SECONDS); + + assertThat("GET Response status", response.getStatus(), is(200)); + try (InputStream inStream = listener.getInputStream()) + { + Files.copy(inStream, localFile); + } + } + + private void clientPUT(Path uploadFile, URI uri) throws InterruptedException, TimeoutException, ExecutionException, IOException + { + ContentResponse response = client.newRequest(uri) + .method(HttpMethod.PUT) + .file(uploadFile, "text/plain") + .send(); + + assertThat("PUT Response status", response.getStatus(), is(204)); + } + + public static void createTestFile(Path file, String lineContent, long lineCount) throws IOException + { + try (BufferedWriter writer = Files.newBufferedWriter(file, UTF_8)) + { + for (int i = 0; i < lineCount; i++) + { + writer.write("" + i + "\t" + lineContent + "\n"); + } + } + } + + public static class ChannelLogger implements HttpChannel.Listener + { + private static final Logger LOG = Log.getLogger(ChannelLogger.class); + + public void onDispatchFailure(Request request, Throwable failure) + { + dump("onDispatchFailure ", request, failure); + } + + public void onRequestFailure(Request request, Throwable failure) + { + dump("onRequestFailure", request, failure); + } + + public void onResponseFailure(Request request, Throwable failure) + { + dump("onResponseFailure ", request, failure); + } + + private void dump(String method, Request request, Throwable failure) + { + HttpChannel channel = request.getHttpChannel(); + LOG.warn(method + " " + channel + " - " + request, failure); + } + } + + public static class UploadDownloadServlet extends DefaultServlet + { + private Path storageDir; + + public UploadDownloadServlet(Path storageDir) + { + this.storageDir = storageDir; + } + + @Override + protected void doPut(HttpServletRequest request, HttpServletResponse response) + throws IOException + { + String path = request.getServletPath(); + while (path.startsWith("/")) + { + path = path.substring(1); + } + + Path file = storageDir.resolve(path); + + // allow repeated tests + Files.deleteIfExists(file); + + try (InputStream inputStream = request.getInputStream()) + { + Files.copy(inputStream, file); + } + + response.setStatus(HttpServletResponse.SC_NO_CONTENT); + } + } +} diff --git a/tests/test-integration/src/test/resources/jetty-logging.properties b/tests/test-integration/src/test/resources/jetty-logging.properties index d79ba45bdd3..f076e496439 100644 --- a/tests/test-integration/src/test/resources/jetty-logging.properties +++ b/tests/test-integration/src/test/resources/jetty-logging.properties @@ -1,4 +1,5 @@ org.eclipse.jetty.util.log.class=org.eclipse.jetty.util.log.StdErrLog -org.eclipse.jetty.LEVEL=INFO +#org.eclipse.jetty.util.log.class=org.eclipse.jetty.util.log.Slf4jLog +org.eclipse.jetty.LEVEL=WARN #org.eclipse.jetty.LEVEL=DEBUG #org.eclipse.jetty.websocket.LEVEL=DEBUG diff --git a/tests/test-integration/src/test/resources/logback.xml b/tests/test-integration/src/test/resources/logback.xml new file mode 100644 index 00000000000..4d184bd4589 --- /dev/null +++ b/tests/test-integration/src/test/resources/logback.xml @@ -0,0 +1,19 @@ + + + target/logs/jetty.txt + false + + %date %level [%thread] %logger{10} [%file:%line] %msg%n + + + + + + %msg%n + + + + + + +