Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
Re: [jetty-users] Premature dispatch creates null value body argument when incoming POST is dispatched before body arrives?

> The other thing is that the server side definitely dispatches to the implementation stub immediately on receipt of the first packet, which only has the headers.

That's correct, and how Jetty operates, and you can even see this behavior if you setup your own HttpChannel.Listener (if using Jetty 9.4.x)

> I’m not sure if Swagger/JAX-RS expects my code to do something special to make sure the body has arrived before starting processing but, as it is, the [mandatory] body parameter is not there and the stub is invoked with a “null” parameter and rejected with a “400" before the client even has a chance to SEND the body (which it does ultimately seem to, at least in some cases, suggesting a race with the error and the server dropping the session)

Request Body contents on a POST would be handled by HttpServletRequest.getParameter*() methods IF the Content-Type was application/x-www-form-urlencoded or multipart/mime (if mime encoded then HttpServletRequest.getParts() would be an option too).

But seeing as you are a PUT and Content-Type application/json, then the body content would only be available in HttpServletRequest.getInputStream() or HttpServletRequest.getReader().
You could choose to use the traditional blocking APIs using InputStream or Reader.
Or you can use the Async I/O options from ServletInputStream.

The body content can only be read once from the options above.
If you have a Filter, for example, that reads the body content (or in the case of POST, it uses one of the HttpServletRequest.getParameter*() methods) then the body content might not be there for the Servlet to read.

Joakim Erdfelt / joakim@xxxxxxxxxxx


On Mon, Apr 22, 2019 at 11:18 AM Patrick Dirks <pdirks@xxxxxxxxxx> wrote:

On Apr 22, 2019, at 9:05 AM, Joakim Erdfelt <joakim@xxxxxxxxxxx> wrote:

> I’m going to dig into the client side a bit more, though, to see why it isn’t just sending the header + body together in the first place.

That is not a requirement for HTTP.
That is perfectly legal for an HTTP client to do.
Heck, it could split up the HTTP into as many TCP packets as it wants, each at 1 byte each, and it will work.
Something else is going on.
I'm wondering what component in Jetty is giving you the 400.
Especially on 9.3.26.v20190403

Can you set a Breakpoint in BadMessageException creation and investigate?


2 breakpoints, at line 57 and 64 (both at the end of the 2 constructors).
Follow the stack, see where these are coming from.
What's going on?

If these breakpoints don't trigger, then the 400 is not coming from Jetty internals, it's coming from your JAX-RS implementation.

Oh, sorry if I wasn’t clear - the 400 is definitely coming from my app, when presented with a request with a “null” body parameter that’s actually required in the API.  I was only surprised that it worked with a Postman client, which definitely sends a properly formatted body on the initial request but not with the cpprest client implementation, which I found sending the information in two packets.  Greg pointed out that as part of Jetty’s testing they send requests 1 byte at a time and expect it to work unchanged so I’m less convinced that 1-vs-2 packets is actually the root cause here.

The other thing is that the server side definitely dispatches to the implementation stub immediately on receipt of the first packet, which only has the headers.  I’m not sure if Swagger/JAX-RS expects my code to do something special to make sure the body has arrived before starting processing but, as it is, the [mandatory] body parameter is not there and the stub is invoked with a “null” parameter and rejected with a “400" before the client even has a chance to SEND the body (which it does ultimately seem to, at least in some cases, suggesting a race with the error and the server dropping the session).

Hence my plan to look a bit more closely at the client to see what prompts the sending of the body but if there’s something I’m missing, I’d love to hear of course.

Thanks again,
-Patrick.

Joakim Erdfelt / joakim@xxxxxxxxxxx


On Mon, Apr 22, 2019 at 10:43 AM Patrick Dirks <pdirks@xxxxxxxxxx> wrote:
Hi Joakim,

On Apr 22, 2019, at 4:18 AM, Joakim Erdfelt <joakim@xxxxxxxxxxx> wrote:

0x00d0:  7469 6f6e 2f6a 736f 6e0d 0a55 7365 722d  tion/json..User-
0x00e0:  4167 656e 743a 0d0a 436f 6e6e 6563 7469  Agent:..Connecti

Here's your problem.

You have a Header "User-Agent" without a value.
This syntax is only valid in the deprecated RFC2616.
If you want a Header without a value in the current RFC7230 it should be ...

Content-Type: application/json
User-Agent: ""
Connection: close

Fix that, try again.
Either remove the field entirely, or make it's value say double-quote.

Thanks for catching that.  I fixed the code to set an actual string there (I just made it “Agent-42”):

08:15:41.251627 IP pdirks-dev-linux.eng.vmware.com.49710 > pdirks-dev-linux.eng.vmware.com.http-alt: Flags [P.], seq 1:215, ack 1, win 342, options [nop,nop,TS val 3514877737 ecr 3514877737], length 214: HTTP: PUT /VMware-XXX/XXX-backend/1.0/hosts HTTP/1.1
0x0000:  4500 010a c479 4000 4006 2f8e 0a14 98df  E....y@.@./.....
0x0010:  0a14 98df c22e 1f90 50f5 eeec 68b1 3876  ........P...h.8v
0x0020:  8018 0156 46e3 0000 0101 080a d180 c729  ...VF..........)
0x0030:  d180 c729 5055 5420 2f56 4d77 6172 652d  ...)PUT./VMware-
0x0040:  5858 582f 5858 582d 6261 636b 656e 642f  XXX/XXX-backend/
0x0050:  312e 302f 686f 7374 7320 4854 5450 2f31  1.0/hosts.HTTP/1
0x0060:  2e31 0d0a 486f 7374 3a20 7064 6972 6b73  .1..Host:.pdirks
0x0070:  2d64 6576 2d6c 696e 7578 2e65 6e67 2e76  -dev-linux.eng.v
0x0080:  6d77 6172 652e 636f 6d3a 3830 3830 0d0a  mware.com:8080..
0x0090:  4163 6365 7074 3a61 7070 6c69 6361 7469  Accept:applicati
0x00a0:  6f6e 2f6a 736f 6e0d 0a43 6f6e 7465 6e74  on/json..Content
0x00b0:  2d4c 656e 6774 683a 3139 0d0a 436f 6e74  -Length:19..Cont
0x00c0:  656e 742d 5479 7065 3a61 7070 6c69 6361  ent-Type:applica
0x00d0:  7469 6f6e 2f6a 736f 6e0d 0a55 7365 722d  tion/json..User-
0x00e0:  4167 656e 743a 4167 656e 742d 3432 0d0a  Agent:Agent-42..
0x00f0:  436f 6e6e 6563 7469 6f6e 3a20 4b65 6570  Connection:.Keep
0x0100:  2d41 6c69 7665 0d0a 0d0a                 -Alive....
08:15:41.254157 IP pdirks-dev-linux.eng.vmware.com.http-alt > pdirks-dev-linux.eng.vmware.com.49710: Flags [P.], seq 1:248, ack 234, win 350, options [nop,nop,TS val 3514877740 ecr 3514877737], length 247: HTTP: HTTP/1.1 400 Bad Request
0x0000:  4500 012b 12ec 4000 4006 e0fa 0a14 98df  E..+..@.@.......
0x0010:  0a14 98df 1f90 c22e 68b1 3876 50f5 efd5  ........h.8vP...
0x0020:  8018 015e 4704 0000 0101 080a d180 c72c  ...^G..........,
0x0030:  d180 c729 4854 5450 2f31 2e31 2034 3030  ...)HTTP/1.1.400
0x0040:  2042 6164 2052 6571 7565 7374 0d0a 4461  .Bad.Request..Da
0x0050:  7465 3a20 4d6f 6e2c 2032 3220 4170 7220  te:.Mon,.22.Apr.
0x0060:  3230 3139 2031 353a 3135 3a34 3120 474d  2019.15:15:41.GM
0x0070:  540d 0a41 6363 6573 732d 436f 6e74 726f  T..Access-Contro
0x0080:  6c2d 416c 6c6f 772d 4f72 6967 696e 3a20  l-Allow-Origin:.
0x0090:  2a0d 0a41 6363 6573 732d 436f 6e74 726f  *..Access-Contro
0x00a0:  6c2d 416c 6c6f 772d 4d65 7468 6f64 733a  l-Allow-Methods:
0x00b0:  2047 4554 2c20 504f 5354 2c20 4445 4c45  .GET,.POST,.DELE
0x00c0:  5445 2c20 5055 540d 0a41 6363 6573 732d  TE,.PUT..Access-
0x00d0:  436f 6e74 726f 6c2d 416c 6c6f 772d 4865  Control-Allow-He
0x00e0:  6164 6572 733a 2043 6f6e 7465 6e74 2d54  aders:.Content-T
0x00f0:  7970 650d 0a43 6f6e 7465 6e74 2d4c 656e  ype..Content-Len
0x0100:  6774 683a 2030 0d0a 5365 7276 6572 3a20  gth:.0..Server:.
0x0110:  4a65 7474 7928 392e 332e 3236 2e76 3230  Jetty(9.3.26.v20
0x0120:  3139 3034 3033 290d 0a0d 0a              190403)….

but that didn’t actually make any difference.  The server stub still got invoked with a null body immediately:

Entering addHost("null")...
Returning BAD_REQUEST because hostSpec.getHostId() == null...

which is exactly what it did before.  I’m going to dig into the client side a bit more, though, to see why it isn’t just sending the header + body together in the first place.

Thanks for the tip,
-Patrick.


Joakim Erdfelt / joakim@xxxxxxxxxxx


On Sun, Apr 21, 2019 at 11:00 PM Patrick Dirks <pdirks@xxxxxxxxxx> wrote:
Hi Olivier,

Thanks a lot - that’ll be the missing link.  For now, I’m OK working with 9.3.x to figure out where things are going so fundamentally off the rails.  There’s got to be something painfully obvious I’m missing somehow.  Greg Wilkins just pointed out they test their builds sending requests as little as 1 byte at a time so it can’t be as simple as 1-vs-2 packets.  There’s probably something in how the cpprest client stubs are generating the request, but darned if I can see it.

As I just wrote to Greg,

I believe the call is being dispatched as soon as the headers arrive because in the ‘tcpdump’ trace I see only the headers go out and immediately the response comes back (with an error).  See below for a (lightly censored) example out of the trace:

16:22:30.919766 IP pdirks-dev-linux.eng.vmware.com.49250 > pdirks-dev-linux.eng.vmware.com.http-alt: Flags [P.], seq 1:207, ack 1, win 342, options [nop,nop,TS val 3457687594 ecr 3457687594], length 206: HTTP: PUT /VMware-XXX/XXX-backend/1.0/hosts HTTP/1.1
0x0000:  4500 0102 09aa 4000 4006 ea65 0a14 98df  E.....@.@..e....
0x0010:  0a14 98df c062 1f90 2b24 0906 cfec aed1  .....b..+$......
0x0020:  8018 0156 46db 0000 0101 080a ce18 202a  ...VF..........*
0x0030:  ce18 202a 5055 5420 2f56 4d77 6172 652d  ...*PUT./VMware-
0x0040:  5858 582f 5858 582d 6261 636b 656e 642f  XXX/XXX-backend/
0x0050:  312e 302f 686f 7374 7320 4854 5450 2f31  1.0/hosts.HTTP/1
0x0060:  2e31 0d0a 486f 7374 3a20 7064 6972 6b73  .1..Host:.pdirks
0x0070:  2d64 6576 2d6c 696e 7578 2e65 6e67 2e76  -dev-linux.eng.v
0x0080:  6d77 6172 652e 636f 6d3a 3830 3830 0d0a  mware.com:8080..
0x0090:  4163 6365 7074 3a61 7070 6c69 6361 7469  Accept:applicati
0x00a0:  6f6e 2f6a 736f 6e0d 0a43 6f6e 7465 6e74  on/json..Content
0x00b0:  2d4c 656e 6774 683a 3139 0d0a 436f 6e74  -Length:19..Cont
0x00c0:  656e 742d 5479 7065 3a61 7070 6c69 6361  ent-Type:applica
0x00d0:  7469 6f6e 2f6a 736f 6e0d 0a55 7365 722d  tion/json..User-
0x00e0:  4167 656e 743a 0d0a 436f 6e6e 6563 7469  Agent:..Connecti
0x00f0:  6f6e 3a20 4b65 6570 2d41 6c69 7665 0d0a  on:.Keep-Alive..
0x0100:  0d0a                                     ..
16:22:30.923503 IP pdirks-dev-linux.eng.vmware.com.http-alt > pdirks-dev-linux.eng.vmware.com.49250: Flags [P.], seq 1:248, ack 226, win 350, options [nop,nop,TS val 3457687598 ecr 3457687594], length 247: HTTP: HTTP/1.1 400 Bad Request
0x0000:  4500 012b ae7e 4000 4006 4568 0a14 98df  E..+.~@.@.Eh....
0x0010:  0a14 98df 1f90 c062 cfec aed1 2b24 09e7  .......b....+$..
0x0020:  8018 015e 4704 0000 0101 080a ce18 202e  ...^G...........
0x0030:  ce18 202a 4854 5450 2f31 2e31 2034 3030  ...*HTTP/1.1.400
0x0040:  2042 6164 2052 6571 7565 7374 0d0a 4461  .Bad.Request..Da
0x0050:  7465 3a20 5375 6e2c 2032 3120 4170 7220  te:.Sun,.21.Apr.
0x0060:  3230 3139 2032 333a 3232 3a33 3020 474d  2019.23:22:30.GM
0x0070:  540d 0a41 6363 6573 732d 436f 6e74 726f  T..Access-Contro
0x0080:  6c2d 416c 6c6f 772d 4f72 6967 696e 3a20  l-Allow-Origin:.
0x0090:  2a0d 0a41 6363 6573 732d 436f 6e74 726f  *..Access-Contro
0x00a0:  6c2d 416c 6c6f 772d 4d65 7468 6f64 733a  l-Allow-Methods:
0x00b0:  2047 4554 2c20 504f 5354 2c20 4445 4c45  .GET,.POST,.DELE
0x00c0:  5445 2c20 5055 540d 0a41 6363 6573 732d  TE,.PUT..Access-
0x00d0:  436f 6e74 726f 6c2d 416c 6c6f 772d 4865  Control-Allow-He
0x00e0:  6164 6572 733a 2043 6f6e 7465 6e74 2d54  aders:.Content-T
0x00f0:  7970 650d 0a43 6f6e 7465 6e74 2d4c 656e  ype..Content-Len
0x0100:  6774 683a 2030 0d0a 5365 7276 6572 3a20  gth:.0..Server:.
0x0110:  4a65 7474 7928 392e 332e 3236 2e76 3230  Jetty(9.3.26.v20
0x0120:  3139 3034 3033 290d 0a0d 0a              190403)....

Interestingly, I see a “PUSH” flag set on the “PUT” packet and I don’t even see the rest of the body in another packet this time, so that suggests the difference is not just 1 vs. 2 packets but some other issue generating a properly formatted body (although it could also be the server dropping the connection before the client gets around to sending it).  Note, though, that the header has “Content-Length:19” which is exactly what I would expect for the length of a properly formatted “{“host-id”:"goofy”}” packet ?

FWIW I don’t get as far as a NPE - I have some logging that logs when a null pointer comes in to the server stub and it decides to reject the call with 400 error (“BAD REQUEST”) so I’m 100% sure my stub is, in fact, being called with a null pointer for the body parameter, whereas with Postman it works as expected, comes in with a non-null pointer, and sees what it expects to see in the body parameter and completes normally.

I appreciate the point-out on “supportedPackagings", though - I’ll let you know when I get a chance to work my way up to 9.4.x.

Thanks,
-Patrick.

On Apr 21, 2019, at 4:45 PM, Olivier Lamy <olamy@xxxxxxxxxxx> wrote:


Hi Patrick,
see inline.
On Sun, Apr 21, 2019 at 5:14 PM Patrick Dirks <pdirks@xxxxxxxxxx> wrote:
Hi Joakim,

On Apr 20, 2019, at 9:36 PM, Joakim Erdfelt <joakim@xxxxxxxxxxx> wrote:

9.2.9 is rather old, even for the EOL 9.2.x series.
Consider using 9.2.28.v20190418.
Or if you want latest stable release, use 9.4.17.v20190418 

Yes, I just noticed on the Jetty web site that 9.2.x was, in fact, EOL.  I’m not sure how my system ended up with 9.2.9 installed - I believe that was hard-wired in the generated SwaggerHub server stubs.

I’m not sure what incompatibilities I should look out for upgrading to 9.4.x.  Offhand, just changing “jetty-version” in the generated pom.xml to 9.4.17.v20190418 makes “man clean package jetty:run” yields a complaint about the “.jar” format swagger-jaxrs-server that gets built not being supported:

[INFO] <<< jetty-maven-plugin:9.4.17.v20190418:run (default-cli) < test-compile @ swagger-jaxrs-server <<<
[INFO] 
[INFO] 
[INFO] --- jetty-maven-plugin:9.4.17.v20190418:run (default-cli) @ swagger-jaxrs-server ---
[INFO] Logging initialized @6783ms to org.eclipse.jetty.util.log.Slf4jLog
[INFO] Skipping swagger-jaxrs-server : packaging type [jar] is unsupported
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  5.980 s
[INFO] Finished at: 2019-04-20T23:57:41-07:00
[INFO] ————————————————————————————————————

which wasn’t exactly what I was hoping for :-)
 
That's something new in 9.4.x ( https://github.com/eclipse/jetty.project/issues/2372 )
You must add this jetty-maven-plugin configuration:
<supportedPackagings>
  <supportedPackaging>jar</supportedPackaging>
</supportedPackagings>

HTH
Olivier
 

OTOH, looking back through the Jetty releases I tried the MUCH more recent 9.3.26.v20190403 and THAT seems to suddenly work as expected!  Looks like this may have been an issue cleaned up since 9.2.9 hit the streets!

I think I’m good with 9.3.26.v20190403!  I’ll test some other client stubs and see if this actually completely resolved the problem but it certainly appears to have fixes this issue.

Thanks for the tip!

Regards,
-Patrick.

Joakim Erdfelt / joakim@xxxxxxxxxxx


On Sat, Apr 20, 2019 at 7:13 PM Patrick Dirks <pdirks@xxxxxxxxxx> wrote:
Hi,

I’m new to Jetty - I'm experimenting with an API on SwaggerHub and I've generated both client-side (cpprest) and server-side (JAX-RS) stubs from the API. My server side is running jetty-9.2.9.v20150224.

When I use a client like Postman, which sends the complete request (headers and body) in a single packet, the server responds as expected. When I use the generated (cpprest) client stubs the request headers come in a first packet and the body in a second packet. The strange part is that, although they re-assemble fine (I can see a valid-looking combined packet in Wireshark), it looks as if the server request is dispatched as soon as the headers arrive, without waiting for the body parameters to arrive (despite the "Content-length" header value)?

As a result the server sees a request that's got a "null" value for the body parameter (even though the parameter is marked as "required"), as if "delayDispatchUntilContent" is false? I've tried adding a "jetty.xml" file that explicitly defaults and sets "delayDispatchUntilContent" to "true" but that doesn't seem to make any difference.  Neither does Swagger 2.0 vs. OpenAPI 3.0 use make any difference.

Any idea what I'm missing here? Any suggestions for a workaround, or a fix?

Thanks in advance!
-Patrick.
_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users
_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://nam04.safelinks.protection.outlook.com/?url="">

_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users


-- 
Olivier
_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://nam04.safelinks.protection.outlook.com/?url="">

_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users
_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://nam04.safelinks.protection.outlook.com/?url="">

_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users
_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://nam04.safelinks.protection.outlook.com/?url="">

_______________________________________________
jetty-users mailing list
jetty-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users

Back to the top