File upload puzzle

[a1730]

Jetty Version
INFO :oejs.Server:main: jetty-12.0.10; built: 2024-05-30T04:40:36.563Z; git: 26106df; jvm 22.0.1+8

Jetty Environment
core,ee8

Java Version
openjdk 22.0.1 2024-04-16
OpenJDK Runtime Environment Temurin-22.0.1+8 (build 22.0.1+8)
OpenJDK 64-Bit Server VM Temurin-22.0.1+8 (build 22.0.1+8, mixed mode)

Question
We have a very simple file upload service that worked very well with Jetty-10 but gets stuck with files larger than 12KB on Jetty-12 throwing a timeout exception.

Type: IOException
Message: java.util.concurrent.TimeoutException: Idle timeout 30000 ms elapsed

What could be blocking file upload? The attached servlet blocks on file upload when the file size is more than 12KB i.e. XLSX_150 works but XLSX_200 hangs. I must be missing a tunable knob.
Please help, I am at a loss where to look.

Thank you.
The servlet: JettyHangingServlet.zip
Jetty Configuration: jetty configuration
Sample files: file_example_XLSX_150.xlsx file_example_XLSX_200.xlsx](https://github.com/user-attachments/files/15856079/file_example_XLSX_200.xlsx)

[sbordet]

I just tried your example, and everything works fine:

client-side:

simon@boron:/tmp/jetty-base$ curl -v -F "file=@/tmp/200.xlsx" http://localhost:8080/upload/aristax
* Host localhost:8080 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:8080...
* Connected to localhost (::1) port 8080
> POST /upload/aristax HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/8.5.0
> Accept: */*
> Content-Length: 14152
> Content-Type: multipart/form-data; boundary=------------------------TlcDU0O9TyZj5ggLOANmwr
> 
* We are completely uploaded and fine
< HTTP/1.1 302 Found
< Server: Jetty(12.0.11-SNAPSHOT)
< Location: http://localhost:8080/eb2b/upload/Edi894ToARISTAX.do
< Content-Length: 0
< 
* Connection #0 to host localhost left intact

server-side:

2024-06-16 18:40:44.702:INFO :ca.JettyHangingServlet:qtp1489069835-49: ContentType multipart/form-data; boundary=------------------------TlcDU0O9TyZj5ggLOANmwr
2024-06-16 18:40:44.702:INFO :ca.JettyHangingServlet:qtp1489069835-49: ContentLength 14152
2024-06-16 18:40:44.702:INFO :ca.JettyHangingServlet:qtp1489069835-49: Content-Transfer-Encoding null
2024-06-16 18:40:44.702:INFO :ca.JettyHangingServlet:qtp1489069835-49: Request: /upload/aristax /upload/aristax 7 aristax
2024-06-16 18:40:44.702:WARN :ca.JettyHangingServlet:qtp1489069835-49: ============================ partner is aristax
2024-06-16 18:40:44.703:WARN :ca.JettyHangingServlet:qtp1489069835-49: --------------------------- working on partner is aristax 1
2024-06-16 18:40:44.703:INFO :ca.JettyHangingServlet:qtp1489069835-49: Parts part is org.eclipse.jetty.ee8.nested.MultiPartFormInputStream$MultiPart :application/octet-stream
2024-06-16 18:40:44.703:INFO :ca.JettyHangingServlet:qtp1489069835-49: Submitted file is 200.xlsx
2024-06-16 18:40:44.703:INFO :ca.JettyHangingServlet:qtp1489069835-49: Part: aristax file 13940
2024-06-16 18:40:44.703:INFO :ca.JettyHangingServlet:qtp1489069835-49: I just need to see this.
2024-06-16 18:40:44.703:INFO :ca.JettyHangingServlet:qtp1489069835-49: Partner aristax EDI file upload [200.xlsx 13Kb], status: Ok.  

[sbordet]

WIth a larger file:

client-side:

simon@boron:/tmp/jetty-base$ curl -v -F "file=@/tmp/doc.pdf" http://localhost:8080/upload/aristax
* Host localhost:8080 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:8080...
* Connected to localhost (::1) port 8080
> POST /upload/aristax HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/8.5.0
> Accept: */*
> Content-Length: 647039
> Content-Type: multipart/form-data; boundary=------------------------pTsUBmC27EgytYosTk9mrd
> 
* We are completely uploaded and fine
< HTTP/1.1 302 Found
< Server: Jetty(12.0.11-SNAPSHOT)
< Location: http://localhost:8080/eb2b/upload/Edi894ToARISTAX.do
< Content-Length: 0
< 
* Connection #0 to host localhost left intact

server-side:

2024-06-16 18:41:47.891:INFO :ca.JettyHangingServlet:qtp1489069835-49: ContentType multipart/form-data; boundary=------------------------pTsUBmC27EgytYosTk9mrd
2024-06-16 18:41:47.891:INFO :ca.JettyHangingServlet:qtp1489069835-49: ContentLength 647039
2024-06-16 18:41:47.891:INFO :ca.JettyHangingServlet:qtp1489069835-49: Content-Transfer-Encoding null
2024-06-16 18:41:47.891:INFO :ca.JettyHangingServlet:qtp1489069835-49: Request: /upload/aristax /upload/aristax 7 aristax
2024-06-16 18:41:47.891:WARN :ca.JettyHangingServlet:qtp1489069835-49: ============================ partner is aristax
2024-06-16 18:41:47.901:WARN :ca.JettyHangingServlet:qtp1489069835-49: --------------------------- working on partner is aristax 1
2024-06-16 18:41:47.901:INFO :ca.JettyHangingServlet:qtp1489069835-49: Parts part is org.eclipse.jetty.ee8.nested.MultiPartFormInputStream$MultiPart :application/pdf
2024-06-16 18:41:47.901:INFO :ca.JettyHangingServlet:qtp1489069835-49: Submitted file is doc.pdf
2024-06-16 18:41:47.901:INFO :ca.JettyHangingServlet:qtp1489069835-49: Part: aristax file 646837
2024-06-16 18:41:47.901:INFO :ca.JettyHangingServlet:qtp1489069835-49: I just need to see this.
2024-06-16 18:41:47.901:INFO :ca.JettyHangingServlet:qtp1489069835-49: Partner aristax EDI file upload [doc.pdf 631Kb], status: Ok.  

[a1730]

Thank you for looking at this issue @sbordet .
I was going to add that we are probably doing something wrong hence the ask for a tunable ... However, we have been using the servlet for years successfully on Jetty-10. We only experience the issue with our Jetty-12 (ee8) install.

How do you recommend we start tracing this beast? Any pointers will be appreciated.
Thanks again.

FWIW, Jetty is behind HAProxy in our deployments.

[sbordet]

Enable org.eclipse.jetty.LEVEL=DEBUG in JETTY_HOME/resources/jetty-logging.properties, then make a request with curl like I did above, and post here the logs.

[a1730]

Thanks @sbordet .
I used curl and it worked (this was on the jetty server) - Linux, it hangs when I went through the browser ( m$windows.)
So I decided to send the log file for that session. My apologies if you were looking for something specific.
Deleted big dump.
Thank you so much.

[a1730]

Hi @sbordet,
I took some time to go through the log files and the only difference that I can see between the failed upload and a successful one is AsyncContentProducer@2e02eaba not ready. This is not the case with a successful upload.
line 687 ... 751

oejen.BlockingContentProducer:qtp1630678941-31: nextContent async producer is not ready, waiting on semaphore LockedSemaphore permits=0
...
oejen.BlockingContentProducer:qtp1630678941-54: onContentProducible releasing semaphore LockedSemaphore permits=0 unready=true

line 1907

oejen.BlockingContentProducer:qtp1630678941-24: onContentProducible releasing semaphore LockedSemaphore permits=0 unready=false

Do you have any recommendations where to look or what to look for comparing line 687 of the attached file to line 1907?

loglog.zip
Thank you very much.

[a1730]

This may help someone someday.

We found out after lots of digging that it was not a Jetty issue naturally 😉

This issue is probably due to different interpretation of HTTP spec. by different proxies. Please see HAProxy doesn't emit :authority when converting h1 --> h2. The comment from Willey was most illuminating to us that this is an HTTP WG issue to clarify.
Looking for workaround, there is no way to tell HAProxy to be rfc7540 compliant, and Jetty server does not seem to have a compliance flag for rfc9113.

The workaround referenced by @capflam or anything on Google search that recommends forcing the http-request uri will eventually lead to issues. i.e.

   http-request set-uri https://%[req.hdr(host)]%[pathq]
   http-request set-uri http://%[baseq]

Trust us; we tested a whole bunch of them with different forwarded/forward-for headers... Just don't go there.

Following the wisdom of the NGINX crew on HTTP/2 to backend, we disabled HTTP/2 from HAProxy to the backend on the final hop and Life is good again.
Thank you for your time.

@sbordet, Thank you!
Thank you all for your support.

[sbordet]

Closing -- I think it was reopened by mistake.

[gregw]

@sbordet do we really want to close this? Should we keep it open to track any discussion with there WG. If ultimately it is an ambiguity that doesn't get fixed/classified, should we provide an option so that we can work with haproxy?

[sbordet]

@gregw okay, but from a server point of view it receives an HTTP/2 request without :authority, which is malformed (barring exceptional cases where there is absolutely no authority -- HTTP/0.9 or similar).

Whether HAProxy or a client is in front of Jetty should not matter.

If HAProxy does not send :authority, but does send Host, we could synthesize :authority from Host (the opposite of what HostHeaderCustomizer does), but I'm more inclined to think this is an HAProxy bug, as it should not generate malformed HTTP/2 requests to backend servers.

[gregw]

I agree it is likely a haproxy bug, but if they don't fix it, then could we provide a request customizer that synthesizes the :authority from a host header? or is that too late?

[sbordet]

@gregw I don't think there are early checks on :authority (there are, for example, for :scheme, :method and :path).

So I think it is doable.

@a1730 would you be interested in trying this out, once implemented?

[a1730]

@sbordet yes, count me in!
Thank you all for reviewing this request.

[sbordet]

@a1730 can you try #12066?

[a1730]

@sbordet I'd love to try #12066 if I know what to do 😃
So, where do I get the build artifacts, preferably something like jetty-home jar file, and how to add the customizer to Jetty-12?
I did not see any build artifacts under Github actions...
I'd love to help but I don't get git and I do not have a maven build infrastructure to build from source so any pointer will be appreciated.

[sbordet]

@olamy can you please help @a1730 (see above)?
I don't recall if we can Maven deploy a PR from our Jenkins?

@a1730 if you want to try to build it yourself (need Java 17 and Maven):

$ git clone https://github.com/jetty/jetty.project.git
$ cd jetty.project
$ git checkout fix/jetty-12.0.x/11926/authority-customizer
$ mvn clean install -DskipTests

Then, in your project, update the Jetty dependencies to 12.0.12-SNAPSHOT, that should be taken from your local Maven repository at $HOME/.m2/repository.

[gregw]

I think you need to use the same-home label to make the home from a CI build available. I'll add to the PR....

[olamy]

I did add the label yesterday, but the PR was failing due to a test failure.
@sbordet we do not deploy snapshots from PRs but only from the main branch jetty-12.0.x
@a1730 once the PR build correctly, you will find artifacts such jetty-home artifact attached to the Jenkins job: https://jenkins.webtide.net/job/jetty.project/view/change-requests/job/PR-12066/

[a1730]

Thank you for the label and build artifact @olamy.
I have just downloaded a jetty-home jar file, and I should have a test result at about this time tomorrow.
@sbordet, do I have to enable any debug flags to get a useful log file for the team?
Thanks all.

[sbordet]

@a1730 I assume your testing went fine?

[a1730]

Yes! Thanks for asking @sbordet
Thanks to the team for taking a look and providing a solution.