Skip to content
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

Fix NPEs in HttpSender.ContentSender #12210

Conversation

lorban
Copy link
Contributor

@lorban lorban commented Aug 29, 2024

Remove contentSender.exchange variable, add null checks, improve toString(), add troubleshooting info

Trying to fix the following exception reported here:

Caused by: java.util.concurrent.ExecutionException: java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.client.transport.HttpExchange.getRequest()" because "exchange" is null
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at org.eclipse.jetty.client.transport.HttpRequest.send(HttpRequest.java:707)
	at <our code, redacted>
	... 18 more
Caused by: java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.client.transport.HttpExchange.getRequest()" because "exchange" is null
	at org.eclipse.jetty.client.transport.HttpSender$ContentSender.process(HttpSender.java:511)
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:262)
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:243)
	at org.eclipse.jetty.client.transport.HttpSender.send(HttpSender.java:85)
	at org.eclipse.jetty.client.transport.internal.HttpChannelOverHTTP.send(HttpChannelOverHTTP.java:86)
	at org.eclipse.jetty.client.transport.HttpChannel.send(HttpChannel.java:142)
	at org.eclipse.jetty.client.transport.HttpConnection.send(HttpConnection.java:112)
	at org.eclipse.jetty.client.transport.internal.HttpConnectionOverHTTP$Delegate.send(HttpConnectionOverHTTP.java:379)
	at org.eclipse.jetty.client.transport.internal.HttpConnectionOverHTTP.send(HttpConnectionOverHTTP.java:168)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:444)
	at org.eclipse.jetty.client.transport.HttpDestination.process(HttpDestination.java:420)
	at org.eclipse.jetty.client.transport.HttpDestination.process(HttpDestination.java:375)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:358)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:352)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:329)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:308)
	at org.eclipse.jetty.client.transport.HttpRequest.sendAsync(HttpRequest.java:751)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:303)
	at org.eclipse.jetty.client.transport.HttpRequest.send(HttpRequest.java:744)
	at org.eclipse.jetty.client.CompletableResponseListener.send(CompletableResponseListener.java:79)
	... 20 more

Note: this is an experimental PR; trying to figure out what's going on, not meant to be merged in.

@lorban
Copy link
Contributor Author

lorban commented Aug 29, 2024

@garydgregory I've prepared a patchset in this branch that contains a tentative fix for that other NPE, as well as some info logging that should tell us more about the state of things where you currently see a NPE.

I'd be glad if you could try out this branch, collect all info logs starting with ISSUE-11841 and report back the outcome here.

Thanks for your help!

@garydgregory
Copy link
Contributor

Hello @lorban

Thank you for the update.

Using git commit ed1cadc449bfd711e7fb5d4d409e4eb57be9321b (HEAD -> jetty-12.0.x, origin/jetty-12.0.x, origin/HEAD), I just saw:

Caused by: java.util.concurrent.ExecutionException: java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.client.transport.HttpExchange.getRequest()" because "exchange" is null
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at org.eclipse.jetty.client.transport.HttpRequest.send(HttpRequest.java:707)
	at <our code, redacted>
	... 18 more
Caused by: java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.client.transport.HttpExchange.getRequest()" because "exchange" is null
	at org.eclipse.jetty.client.transport.HttpSender$ContentSender.process(HttpSender.java:511)
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:262)
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:243)
	at org.eclipse.jetty.client.transport.HttpSender.send(HttpSender.java:85)
	at org.eclipse.jetty.client.transport.internal.HttpChannelOverHTTP.send(HttpChannelOverHTTP.java:86)
	at org.eclipse.jetty.client.transport.HttpChannel.send(HttpChannel.java:142)
	at org.eclipse.jetty.client.transport.HttpConnection.send(HttpConnection.java:112)
	at org.eclipse.jetty.client.transport.internal.HttpConnectionOverHTTP$Delegate.send(HttpConnectionOverHTTP.java:379)
	at org.eclipse.jetty.client.transport.internal.HttpConnectionOverHTTP.send(HttpConnectionOverHTTP.java:168)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:444)
	at org.eclipse.jetty.client.transport.HttpDestination.process(HttpDestination.java:420)
	at org.eclipse.jetty.client.transport.HttpDestination.process(HttpDestination.java:375)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:358)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:352)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:329)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:308)
	at org.eclipse.jetty.client.transport.HttpRequest.sendAsync(HttpRequest.java:751)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:303)
	at org.eclipse.jetty.client.transport.HttpRequest.send(HttpRequest.java:744)
	at org.eclipse.jetty.client.CompletableResponseListener.send(CompletableResponseListener.java:79)
	... 20 more

Jetty is part of a complex stack and I do not have a better test than what I provided in
https://github.com/jetty/jetty.project/pull/11891/files#diff-ec49bc511b8142a36b3a8e51e364ac54db05f3f1442aa58d0468f9bb730baced

@garydgregory
Copy link
Contributor

garydgregory commented Aug 29, 2024

I will pull this branch and test locally...
I'm seeing this error locally when I build with: mvn clean install -pl jetty-core/jetty-client

[ERROR] Tests run: 18, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 631.0 s <<< FAILURE! -- in org.eclipse.jetty.client.ConnectionPoolTest
[ERROR] org.eclipse.jetty.client.ConnectionPoolTest.testConcurrentRequestsWithSlowAddressResolver(ConnectionPoolFactory)[4] -- Time elapsed: 500.2 s <<< FAILURE!
org.opentest4j.AssertionFailedError: expected: <true> but was: <false>
        at org.junit.jupiter.api.AssertionFailureBuilder.build(AssertionFailureBuilder.java:151)
        at org.junit.jupiter.api.AssertionFailureBuilder.buildAndThrow(AssertionFailureBuilder.java:132)
        at org.junit.jupiter.api.AssertTrue.failNotTrue(AssertTrue.java:63)
        at org.junit.jupiter.api.AssertTrue.assertTrue(AssertTrue.java:36)
        at org.junit.jupiter.api.AssertTrue.assertTrue(AssertTrue.java:31)
        at org.junit.jupiter.api.Assertions.assertTrue(Assertions.java:183)
        at [email protected]/org.eclipse.jetty.client.ConnectionPoolTest.testConcurrentRequestsWithSlowAddressResolver(ConnectionPoolTest.java:394)
        at java.base/java.lang.reflect.Method.invoke(Method.java:569)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:992)
        at java.base/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:762)
        at java.base/java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:276)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:992)
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
        at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
        at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)
        at java.base/java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:276)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625)
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
        at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
        at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)
        at java.base/java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:276)
        at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625)
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
        at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
        at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)
        at java.base/java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:194)
        at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373)
        at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182)
        at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655)
        at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622)
        at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165

Using:

Apache Maven 3.9.8 (36645f6c9b5079805ea5009217e36f2cffd34256)
Maven home: C:\java\apache-maven-3.9.8
Java version: 17.0.12, vendor: Eclipse Adoptium, runtime: C:\Program Files\Eclipse Adoptium\jdk-17.0.12.7-hotspot
Default locale: en_US, platform encoding: Cp1252
OS name: "windows 10", version: "10.0", arch: "amd64", family: "windows"

@garydgregory
Copy link
Contributor

garydgregory commented Aug 30, 2024

Hi @lorban,

Any thoughts on the build failures on the GitHub CI (or the one listed)? I'm comfortable testing a branch here when it fails a build.

TY for your thoughts and your work here.

With git at:

commit 1726c8778c0c1a2040d5aafeb265c59ad927e599 (HEAD -> jetty-12.0.x, origin/jetty-12.0.x, origin/HEAD)
Author: Simone Bordet <[email protected]>
Date:   Fri Aug 30 13:01:43 2024 +0300

I current see:

Caused by: java.util.concurrent.ExecutionException: java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.client.transport.HttpExchange.getRequest()" because "exchange" is null
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at org.eclipse.jetty.client.transport.HttpRequest.send(HttpRequest.java:707)
	at <redacted>
	... 18 more
Caused by: java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.client.transport.HttpExchange.getRequest()" because "exchange" is null
	at org.eclipse.jetty.client.transport.HttpSender$ContentSender.process(HttpSender.java:511)
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:262)
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:243)
	at org.eclipse.jetty.client.transport.HttpSender.send(HttpSender.java:85)
	at org.eclipse.jetty.client.transport.internal.HttpChannelOverHTTP.send(HttpChannelOverHTTP.java:86)
	at org.eclipse.jetty.client.transport.HttpChannel.send(HttpChannel.java:142)
	at org.eclipse.jetty.client.transport.HttpConnection.send(HttpConnection.java:112)
	at org.eclipse.jetty.client.transport.internal.HttpConnectionOverHTTP$Delegate.send(HttpConnectionOverHTTP.java:379)
	at org.eclipse.jetty.client.transport.internal.HttpConnectionOverHTTP.send(HttpConnectionOverHTTP.java:168)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:444)
	at org.eclipse.jetty.client.transport.HttpDestination.process(HttpDestination.java:420)
	at org.eclipse.jetty.client.transport.HttpDestination.process(HttpDestination.java:375)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:358)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:352)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:329)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:308)
	at org.eclipse.jetty.client.transport.HttpRequest.sendAsync(HttpRequest.java:751)
	at org.eclipse.jetty.client.transport.HttpDestination.send(HttpDestination.java:303)
	at org.eclipse.jetty.client.transport.HttpRequest.send(HttpRequest.java:744)
	at org.eclipse.jetty.client.CompletableResponseListener.send(CompletableResponseListener.java:79)

Using:

Apache Maven 3.9.9 (8e8579a9e76f7d015ee5ec7bfcdc97d260186937)
Maven home: C:\java\apache-maven-3.9.9
Java version: 17.0.12, vendor: Eclipse Adoptium, runtime: C:\Program Files\Eclipse Adoptium\jdk-17.0.12.7-hotspot
Default locale: en_US, platform encoding: Cp1252
OS name: "windows 10", version: "10.0", arch: "amd64", family: "windows"

@garydgregory
Copy link
Contributor

Small update: Looking at our test logs, it sure seems like the NPE is a lot more likely to occur when the client sends an Expect: 100-continue header...

@lorban lorban force-pushed the experiment/jetty-12.0.x/11841-npe-in-HttpSender-ContentSender branch from 79e16f8 to 7810ea0 Compare September 13, 2024 08:14
@lorban
Copy link
Contributor Author

lorban commented Sep 13, 2024

@garydgregory We've recently identified #12268 which can explains most (all?) of the failures you recently reported.

I've just submitted a preliminary fix in this PR, so again your feedback would be welcome.

Thanks!

@garydgregory
Copy link
Contributor

garydgregory commented Sep 13, 2024

@lorban
I can build and test, but what should I build? this PR or is do I also need to get 4a209ce ?

This PR seems to build 12.0.13-SNAPSHOT, should it be rebased to build 12.0.14-SNAPSHOT?

@lorban lorban force-pushed the experiment/jetty-12.0.x/11841-npe-in-HttpSender-ContentSender branch from 7810ea0 to fee4d7c Compare September 13, 2024 12:37
@lorban
Copy link
Contributor Author

lorban commented Sep 13, 2024

@garydgregory Please build the branch of this PR. I've rebased it on top of the latest 12.0.x branch, and it includes the fix for the IteratingCallback.

@garydgregory
Copy link
Contributor

@lorban
OK, great and TY.

@garydgregory
Copy link
Contributor

Hopefully not related, running 'mvn clean install' at commit fee4d7ca0751941cf733596b130bdbe2d5b27a4d (HEAD -> experiment/jetty-12.0.x/11841-npe-in-HttpSender-ContentSender, origin/experiment/jetty-12.0.x/11841-npe-in-HttpSender-ContentSender) gives me:

Running org.eclipse.jetty.util.resource.FileSystemResourceTest.testResolveRootPath(WorkDir)
[ERROR] Tests run: 44, Failures: 1, Errors: 0, Skipped: 7, Time elapsed: 3.363 s <<< FAILURE! -- in org.eclipse.jetty.util.resource.FileSystemResourceTest
[ERROR] org.eclipse.jetty.util.resource.FileSystemResourceTest.testNotFileURI -- Time elapsed: 0.003 s <<< FAILURE!
org.opentest4j.AssertionFailedError: Expected java.lang.IllegalArgumentException to be thrown, but nothing was thrown.
        at org.junit.jupiter.api.AssertionFailureBuilder.build(AssertionFailureBuilder.java:152)
        at org.junit.jupiter.api.AssertThrows.assertThrows(AssertThrows.java:73)
        at org.junit.jupiter.api.AssertThrows.assertThrows(AssertThrows.java:35)
        at org.junit.jupiter.api.Assertions.assertThrows(Assertions.java:3115)
        at [email protected]/org.eclipse.jetty.util.resource.FileSystemResourceTest.testNotFileURI(FileSystemResourceTest.java:190)
        at java.base/java.lang.reflect.Method.invoke(Method.java:569)
        at java.base/java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:194)
        at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373)
        at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182)
        at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655)
        at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622)
        at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165)

[INFO] Running org.eclipse.jetty.util.resource.UrlResourceFactoryTest

I'll add -DskipTests for now.

Using:

Apache Maven 3.9.9 (8e8579a9e76f7d015ee5ec7bfcdc97d260186937)
Maven home: C:\java\apache-maven-3.9.9
Java version: 17.0.12, vendor: Eclipse Adoptium, runtime: C:\Program Files\Eclipse Adoptium\jdk-17.0.12.7-hotspot
Default locale: en_US, platform encoding: Cp1252
OS name: "windows 10", version: "10.0", arch: "amd64", family: "windows"

@lorban
Copy link
Contributor Author

lorban commented Sep 13, 2024

FileSystemResourceTest.testNotFileURI() is tagged as "flaky", meaning it's not stable. You can safely ignore this failure.

@garydgregory
Copy link
Contributor

@lorban

So far so good, I've been running a test for a few hours without failures!

I'll run our full build and check results in the morning.

@garydgregory
Copy link
Contributor

@lorban

My local tests are green!
Once this PR is merged, I can run a full build from our CI system as an additional check.

@lorban
Copy link
Contributor Author

lorban commented Sep 16, 2024

@garydgregory the fix for the IteratingCallback has been merged. This should be the only change needed from this PR so you should be good to go by building the latest jetty-12.0.x branch.

@garydgregory
Copy link
Contributor

@lorban
TY for the update. Would you please notify when this shows up in a SNAPSHOT build in https://oss.sonatype.org/content/repositories/jetty-snapshots/ ?

@lorban lorban force-pushed the experiment/jetty-12.0.x/11841-npe-in-HttpSender-ContentSender branch 2 times, most recently from 70eb2f2 to f0ae7c3 Compare September 17, 2024 07:49
@lorban lorban force-pushed the experiment/jetty-12.0.x/11841-npe-in-HttpSender-ContentSender branch from f0ae7c3 to 72f9d13 Compare September 17, 2024 07:51
@lorban
Copy link
Contributor Author

lorban commented Sep 17, 2024

@garydgregory The latest 12.0.14-SNAPSHOT containing the fix got successfully deployed to the snapshot repo: https://jenkins.webtide.net/job/nightlies/job/jetty-12.0.x-snapshots-deploy/745/

@garydgregory
Copy link
Contributor

garydgregory commented Sep 17, 2024

TY! I will kick off another build here to double check.

@garydgregory
Copy link
Contributor

@lorban

OK, awesome, green builds here 😄

Would you please set expectations for the timing of the 12.0.14 release?

@sbordet
Copy link
Contributor

sbordet commented Sep 17, 2024

@garydgregory 12.0.14 is scheduled by around end of month.

@garydgregory
Copy link
Contributor

@sbordet
TY for the info.

@lorban
Copy link
Contributor Author

lorban commented Sep 18, 2024

Closing as this was fixed by #12268 and the test reproducing the issue was added by #12286

@lorban lorban closed this Sep 18, 2024
@joakime joakime deleted the experiment/jetty-12.0.x/11841-npe-in-HttpSender-ContentSender branch September 18, 2024 16:01
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants