8308310: HttpClient: Avoid logging or locking from within synchronized blocks #14038

dfuch · 2023-05-17T18:46:35Z

Please find here a change that revisits usage of monitors in the HttpClient.

With Virtual Threads now part of the platform it should be possible to pass a newVirtualThreadPerTaskExecutor to the HttpClient. Logging, when enabled, and when called from a synchronized block, can cause the carrier thread to get pinned in case of contention when printing through the underlying PrintStream.

This change aims at avoiding situations where the carrier threads might get pinned.

Progress

Change must be properly reviewed (1 review required, with at least 1 Reviewer)
Change must not contain extraneous whitespace
Commit message must refer to an issue

Issue

JDK-8308310: HttpClient: Avoid logging or locking from within synchronized blocks

Reviewers

Jaikiran Pai (@jaikiran - Reviewer)

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.org/jdk.git pull/14038/head:pull/14038
$ git checkout pull/14038

Update a local copy of the PR:
$ git checkout pull/14038
$ git pull https://git.openjdk.org/jdk.git pull/14038/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 14038

View PR using the GUI difftool:
$ git pr show -t 14038

Using diff file

Download this PR as a diff file:
https://git.openjdk.org/jdk/pull/14038.diff

Webrev

Link to Webrev Comment

bridgekeeper · 2023-05-17T18:47:44Z

👋 Welcome back dfuchs! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

openjdk · 2023-05-17T18:49:30Z

@dfuch The following labels will be automatically applied to this pull request:

net
security

When this pull request is ready to be reviewed, an "RFR" email will be sent to the corresponding mailing lists. If you would like to change these labels, use the /label pull request command.

mlbridge · 2023-05-17T18:54:20Z

Webrevs

dfuch · 2023-05-17T18:58:53Z

/label remove security

openjdk · 2023-05-17T18:59:52Z

@dfuch
The security label was successfully removed.

test/jdk/java/net/httpclient/AuthFilterCacheTest.java

src/java.net.http/share/classes/jdk/internal/net/http/ConnectionPool.java

src/java.net.http/share/classes/jdk/internal/net/http/Http1Response.java

Co-authored-by: Andrey Turbanov <turbanoff@gmail.com>

…onPool.java Co-authored-by: Andrey Turbanov <turbanoff@gmail.com>

…ponse.java Co-authored-by: Andrey Turbanov <turbanoff@gmail.com>

src/java.net.http/share/classes/jdk/internal/net/http/ConnectionPool.java

src/java.net.http/share/classes/jdk/internal/net/http/Http1Exchange.java

src/java.net.http/share/classes/jdk/internal/net/http/Stream.java

src/java.net.http/share/classes/jdk/internal/net/http/Http1Response.java

openjdk · 2023-05-23T14:33:21Z

@dfuch this pull request can not be integrated into master due to one or more merge conflicts. To resolve these merge conflicts and update this pull request you can run the following commands in the local repository for your personal fork:

git checkout HttpClient-Logging-8308310
git fetch https://git.openjdk.org/jdk.git master
git merge FETCH_HEAD
# resolve conflicts and follow the instructions given by git merge
git commit -m "Merge master"
git push

jaikiran · 2023-05-24T10:35:16Z

src/java.net.http/share/classes/jdk/internal/net/http/ConnectionPool.java

        java.util.stream.Stream<ExpiryEntry> stream() {
            return list.stream();
        }

-        // should only be called while holding a synchronization
-        // lock on the ConnectionPool
+        // should only be called while holding the ConnectionPool stateLock.


Hello Daniel, all these methods which say a lock needs to be held when they are called, should we add a assert stateLock.isHeldByCurrentThread(); to make it verifiable? I understand we didn't have a similar assert when the comment said the method needs to be called while holding the monitor, but since we are changing this part now, perhaps we can add those asserts?

The stateLock variable is not available from within the method:

Non-static field 'stateLock' cannot be referenced from a static context

Thank you, that wasn't clearly noticable in the diff.

jaikiran · 2023-05-24T10:43:53Z

src/java.net.http/share/classes/jdk/internal/net/http/Http1Exchange.java

@@ -342,8 +349,11 @@ CompletableFuture<ExchangeImpl<T>> sendHeadersAsync() {

                        if (debug.on()) debug.log("requestAction.headers");
                        List<ByteBuffer> data = requestAction.headers();
-                        synchronized (lock) {
+                        lock.lock();
+                        try {
                            state = State.HEADERS;


Can this code be replaced by a call to switchState(...) to be consistent with the rest of the places in this class which do a similar call?

jaikiran · 2023-05-24T10:53:54Z

src/java.net.http/share/classes/jdk/internal/net/http/Http1Response.java

            } else if ((state & 0x02) == 0x02) {
                if (debug.on())
                    debug.log("ref count for %s already released", client);
            }
-            state |= 0x02;


It looks like previously (before the changes in this PR), the tryRelease could incorrectly set this state to 0x02 even when the state was 0. From what I see in this change, that seems to have been addressed now.

jaikiran · 2023-05-24T10:55:11Z

src/java.net.http/share/classes/jdk/internal/net/http/Http1Response.java

-        public synchronized void tryRelease() {
-            if (state == 0x01) {
+        public void tryRelease() {
+            if (STATE.compareAndSet(this, (byte)0x01, (byte)0x03)) {


Nit - a space is missing between the cast and the value for the second and third parameters.

OK - will do - though I usually don't put a space there.

It's fine with me in the current form if this wasn't an oversight.

jaikiran · 2023-05-24T10:56:42Z

src/java.net.http/share/classes/jdk/internal/net/http/Http2ClientImpl.java

+
+    private void unlock() {
+        lock.unlock();
+    }


Any specific reason for creating private wrapper methods instead of just using lock.lock() and lock.unlock() at the call sites?

removed private methods

jaikiran · 2023-05-24T11:05:03Z

src/java.net.http/share/classes/jdk/internal/net/http/Http2Connection.java

+    boolean finalStream() {
+        stateLock.lock();
+        try {
+            return finalStream;


Perhaps we can make finalStream volatile and remove the use of locks when accessing and setting it?

Looks doable

jaikiran · 2023-05-24T11:20:45Z

src/java.net.http/share/classes/jdk/internal/net/http/MultiExchange.java

+        Exchange<T> previousExchange;
+        synchronized (this) {
+            previousExchange = this.exchange;
+            this.exchange = exchange;


There's a behavioural change here as compared to before this change. Previously, we used to first call released() on the old exchange and cancel() the new exchange, before setting the this.exchange to the new exchange. Now, with this change, we first switch the this.exchange to the new exchange and then call released() and cancel(). Do you think that could have any (odd) issues?

Good observation. When we reach here the previous exchange is practically terminated. Looking at the implementation of released(), and at the place where setExchange is called, I don't think it matters.

Thank you Daniel for checking.

jaikiran · 2023-05-24T11:40:42Z

test/jdk/java/net/httpclient/ConcurrentResponses.java

@@ -168,13 +178,20 @@ void testAsString(String uri) throws Exception {
                .map(cf -> cf.thenCompose(response -> assertbody(response, requests.get(response.request()))))
                .toArray(CompletableFuture<?>[]::new))
                .join();
+        client.close();
+        virtualExecutor.close();


Could we do this in a try/finally block? Same for the other test method.

Done. Note that I avoided try-with-resource in order to ensure that the client would be closed first.

jaikiran · 2023-05-24T11:48:06Z

test/jdk/java/net/httpclient/ManyRequests.java

@@ -260,13 +271,13 @@ static void test(HttpsServer server, HttpClient client) throws Exception {
                done = true;
            } catch (CompletionException e) {
                if (!Platform.isWindows()) throw e;
-                if (LIMIT.get() < REQUESTS) throw e;
+                if (LIMIT.get() < MAX_LIMIT) throw e;


Previously, LIMIT.get() was being compared against MAX_COUNT, because REQUEST was initialized (as final) to that value. Now it's being compared to MAX_LIMIT. Is this intentional?

Yes. I think the previous behaviour was buggy. The idea is to reduce concurrency if the underlying OS has trouble with too many concurrent connections.

What it says here is that if we already reduced the LIMIT once and it fails again we should fail.

jaikiran · 2023-05-24T11:51:19Z

The tests that have been selectively changed to use virtual threads for the HttpClient (and have been set with -Djdk.tracePinnedThreads=full), I'm guessing were selected based on some of the failures that were noticed when virtual threads were used?

dfuch · 2023-05-24T12:45:44Z

The tests that have been selectively changed to use virtual threads for the HttpClient (and have been set with -Djdk.tracePinnedThreads=full), I'm guessing were selected based on some of the failures that were noticed when virtual threads were used?

Yes - these were the bigger offenders causing virtual threads to get pinned.

jaikiran

The latest changes in f5986f93 look fine to me. There's just one suggestion that's remaining in the ConcurrentResponses test about moving the closing of the client and virtual thread executor in a finally block, but other than that this looks good to me.

openjdk · 2023-05-24T13:03:34Z

@dfuch This change now passes all automated pre-integration checks.

ℹ️ This project also has non-automated pre-integration requirements. Please see the file CONTRIBUTING.md for details.

After integration, the commit message for the final commit will be:

8308310: HttpClient: Avoid logging or locking from within synchronized blocks

Reviewed-by: jpai

You can use pull request commands such as /summary, /contributor and /issue to adjust it as needed.

At the time when this comment was updated there had been 20 new commits pushed to the master branch:

7764f46: 8308761: New test TestHFA needs adaptation for JDK-8308276
d7245f7: 8305578: X11GraphicsDevice.pGetBounds() is slow in remote X11 sessions
544978c: 8298066: java/util/concurrent/locks/Lock/OOMEInAQS.java timed out
65c8dbe: 8171221: Remove -XX:+CheckMemoryInitialization
2d4d850: 8308091: Remove unused iRegIHeapbase() matching operand
b7a84b0: 8308758: Problemlist compiler/c2/irTests/TestVectorConditionalMove.java
20f1535: 8303040: linux PPC64le: Implementation of Foreign Function & Memory API (Preview)
466ec30: 8302736: Major performance regression in Math.log on aarch64
05c095c: 8308151: [JVMCI] capture JVMCI exceptions in hs-err
beb75e6: 8306302: C2 Superword fix: use VectorMaskCmp and VectorBlend instead of CMoveVF/D
... and 10 more: https://git.openjdk.org/jdk/compare/c0c4d771922f8fce36f1014e57d7e7a213243891...master

As there are no conflicts, your changes will automatically be rebased on top of these commits when integrating. If you prefer to avoid this automatic rebasing, please check the documentation for the /integrate command for further details.

➡️ To integrate this PR with the above commit message to the master branch, type /integrate in a new comment.

dfuch · 2023-05-24T14:22:29Z

/integrate

openjdk · 2023-05-24T14:23:35Z

Going to push as commit 736b90d.
Since your change was applied there have been 20 commits pushed to the master branch:

7764f46: 8308761: New test TestHFA needs adaptation for JDK-8308276
d7245f7: 8305578: X11GraphicsDevice.pGetBounds() is slow in remote X11 sessions
544978c: 8298066: java/util/concurrent/locks/Lock/OOMEInAQS.java timed out
65c8dbe: 8171221: Remove -XX:+CheckMemoryInitialization
2d4d850: 8308091: Remove unused iRegIHeapbase() matching operand
b7a84b0: 8308758: Problemlist compiler/c2/irTests/TestVectorConditionalMove.java
20f1535: 8303040: linux PPC64le: Implementation of Foreign Function & Memory API (Preview)
466ec30: 8302736: Major performance regression in Math.log on aarch64
05c095c: 8308151: [JVMCI] capture JVMCI exceptions in hs-err
beb75e6: 8306302: C2 Superword fix: use VectorMaskCmp and VectorBlend instead of CMoveVF/D
... and 10 more: https://git.openjdk.org/jdk/compare/c0c4d771922f8fce36f1014e57d7e7a213243891...master

Your commit was automatically rebased without conflicts.

openjdk · 2023-05-24T14:23:52Z

@dfuch Pushed as commit 736b90d.

💡 You may see a message that your pull request was closed with unmerged commits. This can be safely ignored.

8308310

889122f

openjdk bot changed the title ~~8308310~~ 8308310: HttpClient: Avoid logging or locking from within synchronized blocks May 17, 2023

openjdk bot added the rfr Pull request is ready for review label May 17, 2023

openjdk bot added security security-dev@openjdk.org net net-dev@openjdk.org labels May 17, 2023

openjdk bot removed the security security-dev@openjdk.org label May 17, 2023