OpenJDK (JDK 11) behavior discussion for HttpClient

[Daniel Jeliński]

Hi Asha,
It sounds like you are not using ALPN, but instead start with a HTTP1
connection and upgrade to HTTP2.

The incorrect preface string translates to:
_FIRST_POST_PMDINH_PRI *

Is it correct to assume that "_FIRST_POST_PMDINH_" is the final bytes
of the first POST request? If that's correct, then either the client
or the server handles the content-length header incorrectly.

Can you provide a minimal reproducer?
Regards,
Daniel

pt., 15 wrz 2023 o 14:07 Asha Sunagar <Asha.Sunagar at ibm.com> napisał(a):
>
> Hello Team,
>
>
> We are facing invalid preface issue when we send POST request using HttpClient. We overcame this issue using workaround mentioned in openjdk issue. The workaround was to use a blank request before making post request.
>
>
>
> Based on our below observations, the Preface String is different in Failure & Success case,
>
>
> The Preface String for
> 1.1) Post Request without blank request --> we get GOAWAY Exception (Failure case)
>
> Preface String: [80, 82, 73, 32, 42, 32, 72, 84, 84, 80, 47, 50, 46, 48, 13, 10, 13, 10, 83, 77, 13, 10, 13, 10]
>
> Preface String: [95, 70, 73, 82, 83, 84, 95, 80, 79, 83, 84, 95, 80, 77, 68, 73, 78, 72, 95, 80, 82, 73, 32, 42]
>
> Preface String: [95, 70, 73, 82, 83, 84, 95, 80, 79, 83, 84, 95, 80, 77, 68, 73, 78, 72, 95, 80, 82, 73, 32, 42]
>
>
>
> 1.2) Workaround case with a blank request (Success Case)
>
> Preface String: [80, 82, 73, 32, 42, 32, 72, 84, 84, 80, 47, 50, 46, 48, 13, 10, 13, 10, 83, 77, 13, 10, 13, 10]
>
> Preface String: [80, 82, 73, 32, 42, 32, 72, 84, 84, 80, 47, 50, 46, 48, 13, 10, 13, 10, 83, 77, 13, 10, 13, 10]
>
> Preface String: [80, 82, 73, 32, 42, 32, 72, 84, 84, 80, 47, 50, 46, 48, 13, 10, 13, 10, 83, 77, 13, 10, 13, 10]
>
>
>
> 2) LOGS
> 2.1) Post Request without blank request :We get the error  "an error occurred processing a frame": Failed to complete the connection preface from Liberty server and GOAWAY Exception.
>
> [9/7/23, 15:41:10:595 IST] 00000058 id=00000000 com.ibm.ws.http.channel.h2internal.FrameReadProcessor        3 checkConnectionPreface: processNextFrame-:  stream: 0 frame type: Magic Preface  direction: READ_IN H2InboundLink hc: 101118290
>
> [9/7/23, 15:41:10:595 IST] 00000058 id=00000000 com.ibm.ws.http.channel.h2internal.FrameReadProcessor        3 checkConnectionPreface: Preface String: [95, 70, 73, 82, 83, 84, 95, 80, 79, 83, 84, 95, 80, 77, 68, 73, 78, 72, 95, 80, 82, 73, 32, 42]
>
> [9/7/23, 15:41:10:595 IST] 00000058 id=00000000 SystemOut                                                    O PMDINH, FrameReadProcessor CHECKPOINT 2, throw new ProtocolException --- Connection preface/magic was invalid
>
> [9/7/23, 15:41:10:595 IST] 00000058 id=00000000 SystemOut                                                    O PMDINH, FrameReadProcessor CHECKPOINT 3, throw new ProtocolException --- Cconnection preface
>
> [9/7/23, 15:41:10:595 IST] 00000058 id=00000000 com.ibm.ws.http.channel.h2internal.H2InboundLink             3 processRead: an error occurred processing a frame: Failed to complete the connection preface
>
> [9/7/23, 15:41:10:595 IST] 00000058 id=00000000 com.ibm.ws.http.channel.h2internal.H2InboundLink             3 close(vc,e): :linkstatus: is: INIT :close: H2InboundLink hc: 101118290exception: com.ibm.ws.http.channel.h2internal.exceptions.ProtocolException: Failed to complete the connection preface
>
>
>
> 2.2) Workaround case with a blank request
>
> [9/7/23, 15:54:21:528 IST] 0000005a id=00000000 com.ibm.ws.http.channel.h2internal.FrameReadProcessor        3 checkConnectionPreface: processNextFrame-:  stream: 0 frame type: Magic Preface  direction: READ_IN H2InboundLink hc: 551136004
>
> [9/7/23, 15:54:21:528 IST] 0000005a id=00000000 com.ibm.ws.http.channel.h2internal.FrameReadProcessor        3 checkConnectionPreface: Preface String: [80, 82, 73, 32, 42, 32, 72, 84, 84, 80, 47, 50, 46, 48, 13, 10, 13, 10, 83, 77, 13, 10, 13, 10]
>
> [9/7/23, 15:54:21:528 IST] 0000005a id=00000000 com.ibm.ws.http.channel.h2internal.H2InboundLink             3 createNewInboundLink entry: stream-id: 0
>
> [9/7/23, 15:54:21:528 IST] 0000005a id=00000000 com.ibm.ws.http.channel.internal.inbound.HttpInboundLink
>
>
>
> Please let us to know whether it is an expected behavior or an issue?  Or is there a way to handle such scenarios?
>
>
>
> Thanks & Regards,
>
> Asha H Sunagar
>
> IGA - JTC | Global Business Services – IBM
>
> Phone: +91 8884256034
>
> Email : asha.sunagar at ibm.com
>
>