OpenJDK (JDK 11) behavior discussion for HttpClient

[Daniel Jeliński]

Hi Rajesh,
The test is using our own HTTP2 test server, which is bundled with OpenJDK.
Separately, I checked that Apache Tomcat also upgrades the connection
to HTTP2 after receiving a POST request from HttpClient.
Regards,
Daniel

pon., 18 wrz 2023 o 20:07 Rajesh Gudikoti <ragudiko at in.ibm.com> napisał(a):
>
> Thanks Daniel for the info.
> May I know, what server(application server) you used to test(TrailingHeadersTest) on Sept 15. This issue is reported by customer in Liberty server and we have reproduced the same in liberty server.
>
>
>
> Regards
>
> Rajesh
>
> From: Daniel Jeliński <djelinski1 at gmail.com>
> Date: Monday, 18 September 2023 at 6:22 PM
> To: Asha Sunagar <Asha.Sunagar at ibm.com>
> Cc: Daniel Fuchs <daniel.fuchs at oracle.com>, net-dev at openjdk.org <net-dev at openjdk.org>, Syed Moinudeen1 <smoinud1 at in.ibm.com>, Rajesh Gudikoti <ragudiko at in.ibm.com>, Suman Mitra <summitra at in.ibm.com>, Shruthi Shruthi1 <Shruthi.Shruthi1 at ibm.com>
> Subject: [EXTERNAL] Re: OpenJDK (JDK 11) behavior discussion for HttpClient
>
> Hi Asha,
> The HttpClient follows the RFCs with regard to HTTP2 upgrade, and the
> logs you posted suggest that the HTTP2 server you use does not
> implement them correctly. We have no plans to modify the HttpClient to
> work with such servers.
>
> Your options include:
> - work with the team that maintains the server to get the server issue fixed
> - OR use the current workaround - send a request without payload
> first, then send requests with payload once the upgrade is complete
> - OR use HTTPS to avoid HTTP1->HTTP2 upgrade
> - OR use HTTP1
> - OR provide more information that would confirm that this is a
> HttpClient issue.
>
> Regards,
> Daniel
>
> pon., 18 wrz 2023 o 11:54 Asha Sunagar <Asha.Sunagar at ibm.com> napisał(a):
> >
> > Yes Daniel, I see the same issue with JDK 17 too. I executed the code thrice, so log shows 3 prefaces.
> >
> > -----Original Message-----
> > From: Daniel Fuchs <daniel.fuchs at oracle.com>
> > Sent: Friday, September 15, 2023 6:21 PM
> > To: Asha Sunagar <Asha.Sunagar at ibm.com>; net-dev at openjdk.org
> > Cc: Syed Moinudeen1 <smoinud1 at in.ibm.com>; Rajesh Gudikoti <ragudiko at in.ibm.com>; Suman Mitra <summitra at in.ibm.com>; Shruthi Shruthi1 <Shruthi.Shruthi1 at ibm.com>
> > Subject: [EXTERNAL] Re: OpenJDK (JDK 11) behavior discussion for HttpClient
> >
> > Hi Asha,
> >
> > Thanks for the report. Do you see the same issue when using a more recent version of the JDK (e.g.: 17)?
> >
> > I'm not quite sure why your log show 3 prefaces. Are you sending three requests? The ones starting with 95 looks strange.
> >
> > It looks as if it start with the posted data - as Daniel Jelińsky already suggested.
> >
> > best regards
> >
> > -- daniel
> >
> > On 15/09/2023 10:26, Asha Sunagar wrote:
> > > 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
> > > <https://bugs.openjdk.org/browse/JDK-8198947 >. 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 <mailto:asha.sunagar at ibm.com>
> > >
> >