eclipse-ee4j / eclipse-ee4j/jersey

jersey-netty-connector - When SSL connection is reused entity body is sent before HTTP headers causing an error

Open
#5,272 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
Java
Stars
730
Forks
382
PR merge metrics
No merged PRs in 30d

Description

Using Jersey v2.37 with JDK 11

Use case - uploading a binary file to Oracle object storage in a loop. Alternate requests are suceeding.

iteration 1
- new SSL Connection is established and the request returns a 200

iteration 2
- previously established connection is used. request returns a 400. Everything gets cleaned up - In this case the HTTP headers is not being sent. Only the body causing the server to send a 400 response.

iteration 3
- a new SSL connection is established and the request returns a 200 again.

Client usage -
ClientProperties.ASYNC_THREADPOOL_SIZE is set to 10.
javax.ws.rs.client.Client client = ClientBuilder.newBuilder()
.withConfig(config)
.executorService(ExecutorServiceFactory.create())
.sslContext(sslCtx)
.build();

CompletionStage rsp = builder
.rx()
.method(mMethod, mData);

I don't have a simple reproducer, however I can consistently reproduce this in my code. I have added print statements in the netty-connector code to capture the call path.

**success case**
nioEventLoopGroup-10-2 sslHandler = io.netty.handler.ssl.SslHandler@4f4d21ab
oic-rx-worker-3 nc - Netty Request with entity writeAndFlush - DefaultHttpRequest(decodeResult: success, version: HTTP/1.1)
PUT /n/paasdevoic/b/sindhu_test/o/600657791-f523a48d-590e-4640-a465-1614d9f29d13.xml HTTP/1.1
date: Tue, 28 Feb 2023 19:58:01 GMT
Authorization: Signature keyId="ocid1.***",algorithm="rsa-sha256",headers="date (request-target) host content-length content-type x-content-sha256",signature="WK7/E5/8zELpCcWkhGXQuK***"
x-content-sha256: FOrvFQqkd32JfP1F***
x-span-id: f2cd9b49e846f054
User-Agent: oracle-cloud-rest/21.2.1
host: ****
Content-Length: 7739
Content-Type: application/octet-stream
Accept-Encoding: gzip

oic-rx-worker-1 nc - Writing jerseyChunkedInput - org.glassfish.jersey.netty.connector.internal.JerseyChunkedInput@2cc1ad01
oic-rx-worker-1 , ts = 1677606565426 nc - channel flush

pool-14-thread-7 , ts = 1677606565426 nc - writing entity in executorService thread
pool-14-thread-7 , ts = 1677606565427 nc - invoking jerseyRequest.writeEntity

pool-14-thread-7 , ts = 1677606565428 JerseyChunkedInput : write buf = offst = 0, len = 1958 arr ln = 8192
pool-14-thread-7 , ts = 1677606565428 JerseyChunkedInput : write, queued = true

pool-14-thread-7 , ts = 1677606565431 JerseyChunkedInput : write buf = offst = 0, len = 5781 arr ln = 8192
pool-14-thread-7 , ts = 1677606565431 JerseyChunkedInput : write, queued = true

nioEventLoopGroup-10-2 , ts = 1677606565433 JerseyChunkedInput : readChunk : offset = 1958
nioEventLoopGroup-10-2 JerseyChunkedInput readChunk returning buffer = PooledUnsafeDirectByteBuf(ridx: 0, widx: 1958, cap: 1958)

nioEventLoopGroup-10-2 , ts = 1677606565433 JerseyChunkedInput : readChunk : offset = 7739
nioEventLoopGroup-10-2 JerseyChunkedInput readChunk returning buffer = PooledUnsafeDirectByteBuf(ridx: 0, widx: 5781, cap: 5781)

//Headers sent before body
{"level":"DEBUG","logger":"io.netty.handler.ssl.SslHandler","thread":"nioEventLoopGroup-10-3","ts":1677614281643,"msg":"[id: 0xf968425b, L:/10.244.0.157:55100 - R:objectstorage.us-phoenix-1.o raclecloud.com/134.70.8.1:443] HANDSHAKEN: protocol:TLSv1.2 cipher suite:TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384"}
53774 javax.net.ssl|DEBUG|E8|nioEventLoopGroup-10-3|2023-02-28 19:58:01.645 UTC|SSLEngineOutputRecord.java:271|WRITE: TLS12 application_data, length = 8840
53775 javax.net.ssl|DEBUG|E8|nioEventLoopGroup-10-3|2023-02-28 19:58:01.651 UTC|SSLCipher.java:1743|Plaintext before ENCRYPTION (
53776 0000: 50 55 54 20 2F 6E 2F 70 61 61 73 64 65 76 6F 69 PUT /n/paasdevoi
53777 0010: 63 2F 62 2F 73 69 6E 64 68 75 5F 74 65 73 74 2F c/b/sindhu_test/
53778 0020: 6F 2F 36 30 30 36 35 37 37 39 31 2D 66 35 32 33 o/600657791-f523
53779 0030: 61 34 38 64 2D 35 39 30 65 2D 34 36 34 30 2D 61 a48d-590e-4640-a
53780 0040: 34 36 35 2D 31 36 31 34 64 39 66 32 39 64 31 33 465-1614d9f29d13
53781 0050: 2E 78 6D 6C 20 48 54 54 50 2F 31 2E 31 0D 0A 64 .xml HTTP/1.1..d
53782 0060: 61 74 65 3A 20 54 75 65 2C 20 32 38 20 46 65 62 ate: Tue, 28 Feb
53783 0070: 20 32 30 32 33 20 31 39 3A 35 38 3A 30 31 20 47 2023 19:58:01 G
53784 0080: 4D 54 0D 0A 41 75 74 68 6F 72 69 7A 61 74 69 6F MT..Authorizatio
53785 0090: 6E 3A 20 53 69 67 6E 61 74 75 72 65 20 6B 65 79 n: Signature key
53786 00A0: 49 64 3D 22 6F 63 69 64 31 2E 74 65 6E 61 6E 63 Id="ocid1.tenanc
53787 00B0: 79 2E 6F 63 3....

nioEventLoopGroup-10-2sxsubram jerseyclienthandler channelReadComplete. Notifying response
nioEventLoopGroup-10-2sxsubram jerseyclienthandler request = org.glassfish.jersey.client.ClientRequest@6a605969
nioEventLoopGroup-10-2sxsubram jerseyclienthandler response = DefaultHttpResponse(decodeResult: success, version: HTTP/1.1)
HTTP/1.1 200 OK

**Failed case**
oic-rx-worker-4 nc - Netty Request with entity writeAndFlush - DefaultHttpRequest(decodeResult: success, version: HTTP/1.1)
PUT /n/paasdevoic/b/sindhu_test/o/600657791-f523a48d-590e-4640-a465-1614d9f29d13.xml HTTP/1.1
date: Tue, 28 Feb 2023 19:58:07 GMT
Authorization: Signature keyId="ocid1.***",algorithm="rsa-sha256",headers="date (request-target) host content-length content-type x-content-sha256",signature="iufXQDqRRl8BekC5gfc***"
x-content-sha256: FOrvFQqkd32Jf***
x-span-id: 41d7b5a53701f6c2
User-Agent: oracle-cloud-rest/21.2.1
host: ****
Content-Length: 7739
Content-Type: application/octet-stream
Accept-Encoding: gzip

oic-rx-worker-4 nc - Writing jerseyChunkedInput - org.glassfish.jersey.netty.connector.internal.JerseyChunkedInput@591f7e43
oic-rx-worker-4 , ts = 1677614287195 nc - channel flush
pool-14-thread-1 , ts = 1677614287195 nc - writing entity in executorService thread
pool-14-thread-1 , ts = 1677614287195 nc - invoking jerseyRequest.writeEntity
{"level":"TRACE","logger":"org.glassfish.jersey.inject.hk2.Hk2RequestScope$Instance","thread":"oic-rx-worker-4","ts":1677614287195,"msg":"[DEBUG] Released scope instance Instance{id=0bc69998-7d75-471a-a57e-4f9be8ed7b23, referenceCounter=0, store size=0} on thread oic-rx-worker-4"}

pool-14-thread-1 , ts = 1677614287197 JerseyChunkedInput : write buf = offst = 0, len = 1958 arr ln = 8192
pool-14-thread-1 , ts = 1677614287197 JerseyChunkedInput : write, queued = true

nioEventLoopGroup-10-3 , ts = 1677614287197 JerseyChunkedInput : readChunk : offset = 1958
nioEventLoopGroup-10-3 JerseyChunkedInput readChunk returning buffer = PooledUnsafeDirectByteBuf(ridx: 0, widx: 1958, cap: 1958)

javax.net.ssl|DEBUG|93|pool-14-thread-1|2023-02-28 19:58:07.197 UTC|SSLSocketInputRecord.java:486|Raw read (
0000: 17 03 03 16 AD .....
)
javax.net.ssl|DEBUG|93|pool-14-thread-1|2023-02-28 19:58:07.198 UTC|SSLSocketInputRecord.java:214|READ: TLSv1.2 application_data, length = 5805
javax.net.ssl|DEBUG|E8|nioEventLoopGroup-10-3|2023-02-28 19:58:07.197 UTC|SSLEngineOutputRecord.java:271|WRITE: TLS12 application_data, length = 1958
**//Only the body is being sent**
javax.net.ssl|DEBUG|E8|nioEventLoopGroup-10-3|2023-02-28 19:58:07.217 UTC|SSLCipher.java:1743|Plaintext before ENCRYPTION (
0000: 3C 3F 78 6D 6C 20 76 65 72 73 69 6F 6E 3D 22 31 . .
0050: 20 20 20 20 3C 70 72 65 56 45 45 3E 0A 20 20 20 .
0060: 20 20 20 20 20 20 3C 69 6D 64 54 79 70 65 3E 44 D
0070: 31 49 4C 3C 2F 69 6D 64 54 79 70 65 3E 0A 20 20 1IL.
0080: 20 20 20 20 20 20 20 3C 6D 63 49 53 3E 44 31 53 D1S
0090: 43 3C 2F 6D 63 49 53 3E 0A 20 20 20 20 20 20 20 C.
00A0: 20 20 3C 65 78 74 65 72 6E 61 6C 49 64 3E 66 35 f5

pool-14-thread-1 , ts = 1677614287224 JerseyChunkedInput : write buf = offst = 0, len = 5781 arr ln = 8192
pool-14-thread-1 , ts = 1677614287224 JerseyChunkedInput : write, queued = true
nioEventLoopGroup-10-3 , ts = 1677614287224 JerseyChunkedInput : readChunk : offset = 7739
nioEventLoopGroup-10-3 JerseyChunkedInput readChunk returning buffer = PooledUnsafeDirectByteBuf(ridx: 0, widx: 5781, cap: 5781)
javax.net.ssl|DEBUG|E8|nioEventLoopGroup-10-3|2023-02-28 19:58:07.224 UTC|SSLEngineOutputRecord.java:271|WRITE: TLS12 application_data, length = 5781
javax.net.ssl|DEBUG|E8|nioEventLoopGroup-10-3|2023-02-28 19:58:07.227 UTC|SSLCipher.java:1743|Plaintext before ENCRYPTION (
0000: 30 2E 30 3C 2F 71 3E 0A 20 20 20 20 20 20 20 20 0.0.
0010: 20 20 20 20 3C 2F 6D 4C 3E 0A 20 20 20 20 20 20 .
0020: 20 20 20 20 20 20 3C 6D 4C 3E 0A 20 20 20 20 20 .
0030: 20 20 20 20 20 20 20 20 20 20 3C 73 3E 39 3C 2F 9.
0050: 20 20 3C 64 74 3E 32 30 32 32 2D 30 35 2D 33 31

2022-05-31

nioEventLoopGroup-10-3sxsubram jerseyclienthandler request = org.glassfish.jersey.client.ClientRequest@7c51b903
nioEventLoopGroup-10-3sxsubram jerseyclienthandler response = DefaultHttpResponse(decodeResult: success, version: HTTP/1.0)
HTTP/1.0 400 Bad Request

javax.net.ssl|DEBUG|E8|nioEventLoopGroup-10-3|2023-02-28 19:58:07.232 UTC|Alert.java:238|Received alert message (
"Alert": {
"level" : "warning",
"description": "close_notify"
}
)

I have confirmed that headers are not being sent with strace.

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.