[
https://issues.apache.org/jira/browse/HADOOP-19996?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18122034#comment-18122034
]
Tsz-wo Sze commented on HADOOP-19996:
-------------------------------------
bq. Proposed Fix: Irrespective of any behaviour difference, it would be better
to drain the stream before closing.
[~vikkumar], the proposed fix sounds good. Please make it configurable, in
case that the behavior may change in other Java versions.
> With Java 17 KeepAlive caching not working when KMSClientProvider makes
> requests to KMS
> ---------------------------------------------------------------------------------------
>
> Key: HADOOP-19996
> URL: https://issues.apache.org/jira/browse/HADOOP-19996
> Project: Hadoop Common
> Issue Type: Bug
> Components: hadoop-common
> Reporter: Vikas Kumar
> Assignee: Vikas Kumar
> Priority: Major
>
> Recently after upgrading from Java 8 to Java 17 on one existing cluster, we
> observed more than 70% drop in the throughput between client app using
> KMSClientProvider to make requests to Ranger-KMS.
> Apart from throughput, average latency also increased. As soon as we rollback
> to Java 8, it was back to normal.
> Further we found, Ranger-KMS with Java 17 and client using hadoop-common's
> KMSClientProvider with Java 8 is working fine. If we switch to Java 17 on
> the client side, issue starts occuring.
> *My observation and debugging:*
> I suspected the new features of Java 17 like GC and default TLSv1.3 might be
> impacting the throughput. I tried with parallel GC as well, it didn't help.
> Ranger-KMS and client app were explicitly configured to use TLSv1.2 only.
> Still issue persists.
> Enabled tls debug log and can see very frequent *Connection reset* warning
> stack trace. I know that it may happen when server closes the connection due
> to idleTimeout. But frequency was high in Java 17 env in comparison to very
> few occurrences or zero occurrences in env with Java 8.
> Apart from Connection reset, many "Broken pipe" traces were there.
> *Thread dump analysis on the Ranger-KMS side:*
> At the time when client app was getting Connection reset/broken pipe, many
> of the KMS worker threads were occupied in I/O op with underlying socket's
> stream. Load on KMS was not increasing, many of the threads were idle waiting
> for the new task.
> I observed one difference in Java 17 & Java 8 Socket close stack trace on
> client app side:
> *Following is with Java 8:*
>
> {code:java}
> at sun.net.www.http.HttpClient.closeServer(HttpClient.java:1075)
> at sun.net.www.protocol.https.HttpsClient.closeServer(HttpsClient.java:428)
> at sun.net.www.http.KeepAliveCache.put(KeepAliveCache.java:196)
> at
> sun.net.www.protocol.https.HttpsClient.putInKeepAliveCache(HttpsClient.java:667)
> at sun.net.www.http.HttpClient.finished(HttpClient.java:397)
> at
> sun.net.www.http.ChunkedInputStream.closeUnderlying(ChunkedInputStream.java:219)
> at sun.net.www.http.ChunkedInputStream.processRaw(ChunkedInputStream.java:455)
> at
> sun.net.www.http.ChunkedInputStream.readAheadNonBlocking(ChunkedInputStream.java:520)
> at sun.net.www.http.ChunkedInputStream.readAhead(ChunkedInputStream.java:611)
> at sun.net.www.http.ChunkedInputStream.hurry(ChunkedInputStream.java:768)
> at
> sun.net.www.http.ChunkedInputStream.closeUnderlying(ChunkedInputStream.java:221)
> {code}
> *And following is with Java 17:*
>
>
> {code:java}
> at java.base/sun.net.www.http.HttpClient.closeServer(HttpClient.java:1155)
> at
> java.base/sun.net.www.protocol.https.HttpsClient.closeServer(HttpsClient.java:445)
> at
> java.base/sun.net.www.http.ChunkedInputStream.closeUnderlying(ChunkedInputStream.java:222)
> at
> java.base/sun.net.www.http.ChunkedInputStream.close(ChunkedInputStream.java:769)
> at java.base/java.io.FilterInputStream.close(FilterInputStream.java:179)
> {code}
> Note the difference,
>
> In Java 8 when client calls close() on underlying stream, it tries to drain
> any unread bytes left on the inputStream. And there it succeeds , stream is
> clean and retuned to the KeepAlive cache. You can observe
> *HttpsClient.putInKeepAliveCache*
> Same is not happening in Java 17 cluster. Here also it tries to drain the
> unread bytes but fails. hence connection destroyed and connection caching is
> not happening.
> This behaviour indicated towards possibility of connection leaks.
> Check the code
> [here|https://github.com/apache/hadoop/blob/997fa7c12a407c441855f1a409767f198db68cd3/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/crypto/key/kms/KMSClientProvider.java#L585]
> , In KMSClientProvider.java, when it gets 401 it goes to KMS again with
> required tokens. And for this it creates a new Connection , assign it to
> existing "con" reference variable. It missed to close the older connection.
> In the same method, in finally block it calls
> IOUtils.closeStream(is) for new connection.
>
> *To prove this finding,* If I simply drain the unread bytes (if exists)
> explicitly before calling close(), I start getting similar throughput that I
> was getting with Java 8, now I can't see any Connection reset or errors in
> the log.
>
> For example: Average latency without patch was around 225 ms and after patch
> it reduced to around 60-65 ms.
>
> PS: I read that in higher versions of Java, {{SLSocketImpl}} was completely
> rewritten around {{SSLEngine}} record boundaries. I suspect some behaviour
> difference.
>
> *Proposed Fix:* Irrespective of any behaviour difference, it would be better
> to drain the stream before closing.
>
> Request community members to review this and suggest. If this finding is
> correct, I can raise the PR.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
