-
Notifications
You must be signed in to change notification settings - Fork 1.9k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Cannot invoke "org.eclipse.jetty.client.transport.HttpExchange.getRequest()" because "exchange" is null #11841
Comments
Here is a PR: #11891 |
@garydgregory I'm looking at this, and I think there is something else going on, and the NPE appears to be a red herring. I'll keep the issue posted. |
@sbordet
(full stack below) import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.io.OutputStream;
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;
import java.net.URLDecoder;
import java.net.URLEncoder;
import java.nio.ByteBuffer;
import java.nio.charset.StandardCharsets;
import java.nio.file.DirectoryStream;
import java.nio.file.Files;
import java.nio.file.Path;
import java.util.ArrayList;
import java.util.Collections;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.Random;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.ThreadLocalRandom;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.TimeoutException;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.zip.GZIPInputStream;
import java.util.zip.GZIPOutputStream;
import java.util.zip.ZipEntry;
import java.util.zip.ZipInputStream;
import java.util.zip.ZipOutputStream;
import jakarta.servlet.ServletException;
import jakarta.servlet.ServletInputStream;
import jakarta.servlet.ServletOutputStream;
import jakarta.servlet.http.HttpServlet;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.apache.hc.client5.http.config.RequestConfig;
import org.apache.hc.client5.http.impl.classic.CloseableHttpClient;
import org.apache.hc.client5.http.impl.classic.HttpClients;
import org.apache.hc.client5.http.impl.routing.DefaultProxyRoutePlanner;
import org.apache.hc.client5.http.routing.HttpRoutePlanner;
import org.apache.hc.core5.http.ClassicHttpRequest;
import org.apache.hc.core5.http.ContentType;
import org.apache.hc.core5.http.HttpEntity;
import org.apache.hc.core5.http.HttpHost;
import org.apache.hc.core5.http.io.entity.ByteArrayEntity;
import org.apache.hc.core5.http.io.entity.EntityUtils;
import org.apache.hc.core5.http.io.support.ClassicRequestBuilder;
import org.apache.hc.core5.util.Timeout;
import org.eclipse.jetty.client.AsyncRequestContent;
import org.eclipse.jetty.client.BytesRequestContent;
import org.eclipse.jetty.client.CompletableResponseListener;
import org.eclipse.jetty.client.ContentResponse;
import org.eclipse.jetty.client.HttpClient;
import org.eclipse.jetty.client.HttpProxy;
import org.eclipse.jetty.client.Request;
import org.eclipse.jetty.client.Response;
import org.eclipse.jetty.ee9.servlet.ServletContextHandler;
import org.eclipse.jetty.ee9.servlet.ServletHolder;
import org.eclipse.jetty.http.HttpFields;
import org.eclipse.jetty.http.HttpHeader;
import org.eclipse.jetty.http.HttpHeaderValue;
import org.eclipse.jetty.http.HttpStatus;
import org.eclipse.jetty.io.RuntimeIOException;
import org.eclipse.jetty.logging.StacklessLogging;
import org.eclipse.jetty.server.HttpConfiguration;
import org.eclipse.jetty.server.HttpConnectionFactory;
import org.eclipse.jetty.server.Server;
import org.eclipse.jetty.server.ServerConnector;
import org.eclipse.jetty.toolchain.test.jupiter.WorkDir;
import org.eclipse.jetty.toolchain.test.jupiter.WorkDirExtension;
import org.eclipse.jetty.util.BufferUtil;
import org.eclipse.jetty.util.Callback;
import org.eclipse.jetty.util.IO;
import org.eclipse.jetty.util.Utf8StringBuilder;
import org.eclipse.jetty.util.ajax.JSON;
import org.eclipse.jetty.util.component.LifeCycle;
import org.eclipse.jetty.util.thread.QueuedThreadPool;
import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.condition.OS;
import org.junit.jupiter.api.extension.ExtendWith;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
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.assertNull;
import static org.junit.jupiter.api.Assertions.assertTrue;
// This is in AsyncMiddleManServletTest ...
@Test
public void testServletExpect100ApacheHttpClient5() throws Exception
{
startServer(new HttpServlet()
{
private AtomicInteger count = new AtomicInteger();
@Override
protected void service(HttpServletRequest request, HttpServletResponse response) throws IOException
{
// Adding logging may slow things down enough to not hang
// System.out.printf("Origin servicing %d%n", count.incrementAndGet());
// Send the 100 Continue.
ServletInputStream input = request.getInputStream();
// Echo the content.
IO.copy(input, response.getOutputStream());
// Slowing down the origin allows the test to not hang sometimes
// try {
// Thread.sleep(50);
// } catch (InterruptedException e) {
// e.printStackTrace();
// }
}
});
startProxy(new AsyncMiddleManServlet()
{
protected void service(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException
{
// Adding logging may slow things down enough to not hang
// System.out.printf("AsyncMiddleManServlet servicing %n");
super.service(request, response);
}
});
RequestConfig requestConfig = RequestConfig.custom()
.setExpectContinueEnabled(true)
.setResponseTimeout(5, TimeUnit.SECONDS)
.build();
HttpHost proxyHost = new HttpHost("localhost", proxyConnector.getLocalPort());
HttpHost targetHost = new HttpHost("localhost", serverConnector.getLocalPort());
HttpRoutePlanner routePlanner = new DefaultProxyRoutePlanner(proxyHost);
try (CloseableHttpClient httpclient = HttpClients.custom()
.setDefaultRequestConfig(requestConfig)
.setRoutePlanner(routePlanner)
.build()) {
// loop to attempt increase odds of hanging
for (int i = 1; i <= 500; i++) {
long start = System.currentTimeMillis();
System.out.printf("Sending #%d%n", i);
ClassicHttpRequest request = ClassicRequestBuilder.post("http://localhost:" + serverConnector.getLocalPort())
.setHeader(HttpHeader.EXPECT.toString(), HttpHeaderValue.CONTINUE.toString())
.setEntity("a")
.build();
httpclient.execute(targetHost, request, response -> {
System.out.println(response.getCode() + " " + response.getReasonPhrase());
assertEquals(200, response.getCode());
HttpEntity entity = response.getEntity();
EntityUtils.consume(entity);
return null;
});
System.out.printf(" %,d ms%n", System.currentTimeMillis() - start);
}
}
} Randomly produces (you might have to try a few times and/or stress the CPU):
The most simple way to see this stack trace is to add a call to protected int proxyResponseStatus(Throwable failure)
{
failure.printStackTrace();
return failure instanceof TimeoutException
? HttpStatus.GATEWAY_TIMEOUT_504
: HttpStatus.BAD_GATEWAY_502;
} Using logging can affect the timing and randomness too much to easily reproduce this. |
@garydgregory we can reproduce both exceptions (NPE and demand pending), but still working on a better solution that would avoid both, rather than guarding against. |
@sbordet Thank you for the update. Looking forward to a solution 😄 |
@garydgregory how sure you are that you are not sending a request with Because I can reproduce the issue with that combination, but as soon as there is a content, it's not reproducible. We should support that combination, I think, but it's technically not necessary to send expect 100-Continue if there is no content. |
Hello @sbordet, Yes, it is reproducible with and without an HTTP body. Note that the randomly failing test above uses an HTTP POST with a one-character body. This showcases the observation that the shorter the body, the easier it might be to reproduce. Reproducing the issue more reliably may require using a CPU stress program like Micorsoft SysInternal’s “CPU Stres” (Windows) app. That’s the case on my laptop: ThinkPad L15; Windows 10 (22H2 build 19045.4412); CPU 11th Gen Intel(R) Core(TM) i7-1165G7 @ 2.80GHz 2.80 GHz; 16 GB RAM. I agree with your statement that an expect 100 is not needed if there is no body but unfortunately that’s not what we have to support in the real world with actual client apps. Some of our testing and actual usage reflects what we've seen HTTP clients send our server in the wild. We have instances where the HTTP framework used on the client side which we do not control, enables expect 100, whether it's needed or not. We must deal with it, which means for us that Jetty should allow it without throwing NPEs or “demand pending” exception (albeit random but reproducible). To recap, there are several issues at play that are likely related, three exceptions: The two NPEs and the “demand pending” exceptions, plus the Jetty client hanging. Gathering links for record keeping:
TY! |
Hello @sbordet |
@garydgregory thanks for the offer, but unfortunately I don't see much you could do to help speeding up the resolution of this bug. The team is a bit stretched thin at the moment so it's hard to find cycles, but I promise we haven't forgotten about you and will get this fixed ASAP. I'm sorry about having to make you wait. |
@sbordet Thank you for the update! 😄 |
jetty/jetty.project#11841 has an NPE when using 100-Continue. This hack is a workaround. - Create a new module that generates a JAR that will sort first in the classpath - Put a hacked version of Jetty's `HttpSender` in this module that has a fix - The Java classloader will load this version of the class first, thus working around the problem This hack should be removed as soon as possible
jetty/jetty.project#11841 has an NPE when using 100-Continue. This hack is a workaround. - Create a new module that generates a JAR that will sort first in the classpath - Put a hacked version of Jetty's `HttpSender` in this module that has a fix - The Java classloader will load this version of the class first, thus working around the problem This hack should be removed as soon as possible
jetty/jetty.project#11841 has an NPE when using 100-Continue. This hack is a workaround. - Create a new module that generates a JAR that will sort first in the classpath - Put a hacked version of Jetty's `HttpSender` in this module that has a fix - The Java classloader will load this version of the class first, thus working around the problem This hack should be removed as soon as possible
jetty/jetty.project#11841 has an NPE when using 100-Continue. This hack is a workaround. - Create a new module that generates a JAR that will sort first in the classpath - Put a hacked version of Jetty's `HttpSender` in this module that has a fix - The Java classloader will load this version of the class first, thus working around the problem This hack should be removed as soon as possible
jetty/jetty.project#11841 has an NPE when using 100-Continue. This hack is a workaround. - Create a new module that generates a JAR that will sort first in the classpath - Put a hacked version of Jetty's `HttpSender` in this module that has a fix - The Java classloader will load this version of the class first, thus working around the problem This hack should be removed as soon as possible
jetty/jetty.project#11841 has an NPE when using 100-Continue. This hack is a workaround. - Create a new module that generates a JAR that will sort first in the classpath - Put a hacked version of Jetty's `HttpSender` in this module that has a fix - The Java classloader will load this version of the class first, thus working around the problem This hack should be removed as soon as possible
jetty/jetty.project#11841 has an NPE when using 100-Continue. This hack is a workaround. - Create a new module that generates a JAR that will sort first in the classpath - Put a hacked version of Jetty's `HttpSender` in this module that has a fix - The Java classloader will load this version of the class first, thus working around the problem This hack should be removed as soon as possible
@garydgregory sorry it took so long, but there were multiple issues, and it took a while to get a grip on all of them. Can you please try branch |
Thank you @sbordet I will test... |
Hello @sbordet I built and installed ( Two items of note:
This is different from the other HTTP clients we test and a difference in behavior from 11.x we'd need to adapt unless it is a mistake. Please let me know.
Well done & thank you! |
@garydgregory thanks for the feedback! The first bullet should be addressed by 4e9755d, so perhaps you can update to the latest branch code and try again? The second bullet was necessary, but that method should not be overridden or called by applications. |
Thank you for the update, I'll pull, build, and test next. WRT to the |
Hello @sbordet |
OK, I think we're good with this branch! Thank you! What are expectations regarding a merge and release? (Do you have a public snapshot Maven repository?) Details: Our tests made some special allowances for some probably unusual behavior in Jetty 11.0.20 where we saw Jetty return a 417 "Expectation Failed" for DELETE, GET, and PATCH requests without a body but with an Expect 100 header. It's simple enough to update these tests on our end. |
@garydgregory once merged a nightly build will push snapshot to https://oss.sonatype.org/content/repositories/jetty-snapshots
|
TY @olamy I will test on the next build now that the PR has been merged. |
@garydgregory https://jenkins.webtide.net/job/nightlies/job/jetty-12.0.x-snapshots-deploy/ build 710 will do this for you |
Arg, using 12.0.13-SNAPSHOT, I just got a random:
Any thoughts? |
I've updated the test to show the failure still occurs, always, eventually, for me. I would be curious to see what your testing reveals. The test is in https://github.com/garydgregory/jetty.project/pull/new/12.0.x_issue_11841_NPE Run This test shows the NPEs on the console. Eventually, it will fail the test which checks for replies with status 200, for example:
I am using:
|
@garydgregory we're working on it, @lorban will update this and/or open a new issue. |
Signed-off-by: Ludovic Orban <[email protected]>
Signed-off-by: Ludovic Orban <[email protected]>
Jetty version(s)
12.0.9
Jetty Environment
ee9
Java
Maven
OS type/version
Description
Perhaps, coincidentally, I just saw a similar stack trace with an another test; note that our custom servlet subclasses Jetty's AsyncMiddleManServlet, so I am not sure if the stack traces below are from the client side since the test uses the Jetty client or the server side since the AsyncMiddleManServlet also uses the Jetty client.
Note that the test hangs, perhaps due to the second stack trace in the block above.
How to reproduce?
The reproducer is in PR: #11891, but it is "random", sometimes it happens, sometimes is does not. Using Microsoft's SysInternal's CPU Stres tool helps recreate the issue.
This stack trace is from a test case using a Jetty 12 HTTP Client to a Jetty 12 Server using a custom AsyncMiddleManServlet subclass. I can't share any of it unfortunately.
I am wondering if it is possible that there is some asynchronous bad luck involved here.
The text was updated successfully, but these errors were encountered: