ZOOKEEPER-4293: Lock Contention in ClientCnxnSocketNetty by MikeEdgar · Pull Request #1917 · apache/zookeeper

MikeEdgar · 2022-08-18T15:20:45Z

Check for failed/cancelled ChannelFutures before acquiring connectLock. This prevents lock contention where cleanup is unable to complete.

Replaces #1713 (target master rather than branch-3.5)

sonatype-lift · 2022-10-21T14:18:18Z

⚠️ 52 God Classes were detected by Lift in this project. Visit the Lift web console for more details.

MikeEdgar · 2022-10-21T18:21:43Z

@eolivelli , @maoling - please take a look when you have a chance. This replaces #1713 that you looked at last year.

eolivelli

good catch

nice work

LGTM

@anmolnar @phunt @symat PTAL

eolivelli · 2022-12-02T11:38:44Z

it looks some test related to this patch failed on CI

can you please take a look @MikeEdgar ?

MikeEdgar · 2022-12-05T21:37:05Z

@eolivelli , I've made a change that should address the NPE in the new test.

Question.. I see errors locally around org.apache.zookeeper.server.FollowerRequestProcessorTest having a bad package declaration. Is this intended?

MikeEdgar · 2023-04-11T23:44:07Z

@eolivelli , please take another look.

MikeEdgar · 2023-05-10T11:59:06Z

@eolivelli @anmolnar @phunt @symat PTAL. The CI has not yet run with the test fix.

Please also note my earlier question regarding FollowerRequestProcessorTest. The package declaration does not match the source directory. Is this intended?

zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/FollowerRequestProcessorTest.java

Line 19 in a64dbf5

package org.apache.zookeeper.server.quorum;

kezhuw

I submit a reproducible test in kezhuw@0f2610b. From the test case, I think we should fix two sub issues:

Deadlock due to synchronous close and only one event loop thread.
Prevent completion of old connection from interfering current connection.

I have left comments for these two.

I hope this test case could help in reviewing.

kezhuw · 2023-05-19T09:15:21Z

zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxnSocketNetty.java

+                afterConnectFutureCancel();
            }
            if (channel != null) {
                channel.close().syncUninterruptibly();


I think it is a good to move this blocking syncUninterruptibly part out of lock scope. This could also solve the deadlock issue.

kezhuw · 2023-05-19T09:42:31Z

zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxnSocketNetty.java

        connectLock.lock();
        try {
            if (connectFuture != null) {
                connectFuture.cancel(false);


After taking a look at netty code AbstractNioChannel::connect, AbstractEpollChannel::connect and AbstractKQueueChannel::connect, I think this statement connectFuture.cancel(false) cloud be the root cause.

Basically, a connecting future is uncancellable which means connectFuture.cancel(false) could be a nop. So, the old connectFuture could still pending for completion. When we cleanup new connectFuture and old connectFuture completes, they are stuck due to leak of event threads to complete channel.close().syncUninterruptibly()(invoke close in event thread).

I think we could also wait connectFuture to complete in cleanup, but I don't think it is a good. Connection timeout is a possible reason for us to fall here. It is nonsense to block next connection for the same reason.

I have watched this issue for a while, and could not image a situation where there is single connectFuture and this stuck emerged. The channel.close().syncUninterruptibly() means its connectFuture already completed successfully.

zookeeper/zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxnSocketNetty.java

Line 86 in a64dbf5

eventLoopGroup = NettyUtils.newNioOrEpollEventLoopGroup(1 /* nThreads */);

kezhuw · 2023-05-19T17:21:59Z

zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxnSocketNetty.java

        }
    }

+    boolean cancelled(ChannelFuture channelFuture) {


I think we could concentrate more on identity of channelFuture and connectFuture. This will make it clear that channelFuture could come from a old connection. Better to document a bit.

It is also possible that new connection is not completed yet. In this case, old connection should be simply filtered out, otherwise we could introduce inconsistence with outside world.

MikeEdgar · 2023-10-12T17:17:21Z

@eolivelli , what are you thoughts on @kezhuw's comments? Does this PR need additional updates or can it be accepted as-is?

kezhuw

I think the fix clould be as simple as droping syncUninterruptibly from channel.close().syncUninterruptibly(). This way we break the deadlock chain.

netty/netty#13849 probably "fixed" this. But I think it is still vital for us to realize that completed channelFuture may belong to old dangling connection. So I am tend to fix this in our side (also).

kezhuw · 2024-08-26T13:56:49Z

zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxnSocketNetty.java

                        if (!channelFuture.isSuccess()) {
                            LOG.warn("future isn't success.", channelFuture.cause());
                            return;
-                        } else if (connectFuture == null) {


How about simple channelFuture != connectFuture in earlier stage ? This should cover connectFuture == null. In case of channelFuture != connectFuture we should do nothing but simple return.

kezhuw · 2024-08-26T13:59:39Z

zookeeper-server/src/main/java/org/apache/zookeeper/ClientCnxnSocketNetty.java

+                afterConnectFutureCancel();
            }
            if (channel != null) {
                channel.close().syncUninterruptibly();


How about drop .syncUninterruptibly() part ? This way we will not wait for channel close completion callback which could deadlock with old connectFuture's completion callback.

kezhuw · 2024-08-26T14:17:09Z

netty/netty#13849 probably "fixed" this.

I confirmed this with kezhuw@0f2610b.

After netty/netty#13849, connectFuture.cancel(false) will fire cancellation completion callback before next connection in netty event group. So there will be no ongoing connecting future in next iteration. But I am not sure whether there are other paths/conditions leading to uncancellable connecting future.

Though, I am still prefer to fix this in ZooKeeper side.

MikeEdgar · 2024-08-28T11:12:45Z

@kezhuw , @eolivelli , I'm not in a position at the moment to devote much time to reworking and testing this PR, especially in an integrated environment where the issue originally occurred for us. I wonder if it needs the adjustments proposed by @kezhuw, whether it should be a separate PR and just close this one.

Please let me know your thoughts.

anmolnar · 2024-09-11T20:27:59Z

I think the fix clould be as simple as droping syncUninterruptibly from channel.close().syncUninterruptibly(). This way we break the deadlock chain.

@MikeEdgar @kezhuw

Calling a sync method in an async operation inside a lock is a code smell I believe, so I tend to prefer this solution over what the patch suggests. Is this sync call was the root cause of the original lock contention? I mean did you see that the thread is waiting for this call in particular and cannot release the lock?

kezhuw · 2024-09-12T07:56:04Z

The jira ZOOKEEPER-4293 has the deadlock stack dump. Below is what kezhuw@0f2610b reproduced:

Send thread which is holding the lock blocks on channel closing future.
Cancellation of connectFuture from previous run blocks on acquiring lock. This occupies the sole event loop thread.
Channel closing is waits for event loop thread.

graph TD;
    SendThread -- blocks on --- ChannelClosing[channel closing];
    ChannelClosing[channel closing] -- waits for event loop --- ConnectFutureCancellation[old connection cancellation];
    ConnectFutureCancellation[old connection cancellation] -- blocks on lock --- SendThread;

I think the bug is multi-folds:

Netty event group uses only one thread.
Channel is closed synchronous under lock.
Connecting future is uncancellable. So connectFuture.cancel(false) is a nop for connecting future.

Theoretically, we can fix the deadlock by breaking any of the above. netty/netty#13849 breaks the third. I do think bump netty version cloud fix this deadlock. But I also think it might be fragile to depend on bump dependency version to fix bug as netty version could be pinned/upgraded independently. So, personally I prefer to fix it in our side.

cc @anmolnar

anmolnar · 2024-09-12T14:35:42Z

Thanks for the clarification @kezhuw , I appreciate your nice diagram.
I agree with you that we should fix this on our side too, so I suggest the two above mentioned things to do:

Bump Netty version
Remove .syncUninterruptibly()

Thoughts?

kezhuw · 2024-09-12T14:52:31Z

@anmolnar Good to go.

anmolnar · 2024-09-12T15:06:10Z

@MikeEdgar What do you think?
Would you mind modifying your patch accordingly?

MikeEdgar · 2024-09-12T20:25:57Z

@anmolnar, @kezhuw the third commit in this PR includes the latest modifications. I think I understood what you were looking for, but please confirm. Note, bumping the Netty version to the latest 4.1 release also required a minor change to account for a deprecated method.

anmolnar

@MikeEdgar

Sorry I meant we didn't need this modification at all. Instead just do the 2 things that was mentioned in the previous comment.

Signed-off-by: Michael Edgar <medgar@redhat.com>

MikeEdgar · 2024-09-12T22:09:28Z

Sorry I meant we didn't need this modification at all. Instead just do the 2 things that was mentioned in the previous comment.

@anmolnar - done

MikeEdgar · 2024-09-18T20:22:05Z

@anmolnar @kezhuw let me know if this looks as you're expecting.

anmolnar

lgtm.

@eolivelli @kezhuw PTAL.

kezhuw

LGTM

kezhuw · 2024-09-19T14:23:39Z

zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/UnifiedServerSocket.java

            }

-            if (bytesRead == litmus.length && SslHandler.isEncrypted(Unpooled.wrappedBuffer(litmus))) {
+            if (bytesRead == litmus.length && SslHandler.isEncrypted(Unpooled.wrappedBuffer(litmus), false)) {


This variant is brand new in netty-4.1.113.Final, so this patch will enforce netty version. Given my comments #1917 (comment), I am +1 to this. So, client will have to bump its netty version to match this patch in compilation.

netty commit: netty/netty@dc30c33#diff-963dd9b8e77e913395273812889e9b6f2f449fe55e2b748b95311b219d1c58faR1286

Isn't that a problem if we backport this to 3.9? (I want to)
Can we just use another variant which is backward compatible?

The only other variant is the deprecated one, which fails to compile due to the -Werror flag. This file change could possibly be left out of a backport which uses an older netty version.

No worries, we'll upgrade on 3.9 too.

anmolnar · 2024-09-19T15:50:10Z

cppunit tests are stuck here too

…ly (#1917) Reviewers: anmolnar, kezhuw Author: MikeEdgar Closes #1917 from MikeEdgar/ZOOKEEPER-4293

anmolnar · 2024-09-19T19:34:34Z

Merged. Thanks @MikeEdgar !
I also added you to contributors list in Jira.

…nterruptibly (apache#1917) Reviewers: anmolnar, kezhuw Author: MikeEdgar Closes apache#1917 from MikeEdgar/ZOOKEEPER-4293 (cherry picked from commit 9df310a)

…ly (apache#1917) Reviewers: anmolnar, kezhuw Author: MikeEdgar Closes apache#1917 from MikeEdgar/ZOOKEEPER-4293

…adlock) (branch-3.8 backport) ZOOKEEPER-4293: Bump netty to 4.1.113.Final, remove syncUninterruptibly (#1917) Reviewers: anmolnar, kezhuw Author: MikeEdgar Closes #1917 from MikeEdgar/ZOOKEEPER-4293 Reviewers: kezhuw Author: anmolnar Closes #2284 from anmolnar/ZOOKEEPER-4293_38

…ly (apache#1917) Reviewers: anmolnar, kezhuw Author: MikeEdgar Closes apache#1917 from MikeEdgar/ZOOKEEPER-4293

MikeEdgar force-pushed the ZOOKEEPER-4293 branch from 012a45b to 3ae920b Compare August 19, 2022 00:22

MikeEdgar force-pushed the ZOOKEEPER-4293 branch from 3ae920b to 0c4be56 Compare October 21, 2022 14:08

MikeEdgar force-pushed the ZOOKEEPER-4293 branch 2 times, most recently from b4797a9 to 052cce2 Compare October 21, 2022 17:10

eolivelli approved these changes Dec 2, 2022

View reviewed changes

MikeEdgar force-pushed the ZOOKEEPER-4293 branch from 4f2d753 to b24ffb0 Compare April 11, 2023 23:43

kezhuw reviewed May 19, 2023

View reviewed changes

ztzg force-pushed the master branch from 1c60545 to e2070be Compare October 3, 2023 12:57

kezhuw reviewed Aug 26, 2024

View reviewed changes

kezhuw requested review from eolivelli and kezhuw August 26, 2024 14:18

MikeEdgar force-pushed the ZOOKEEPER-4293 branch from b24ffb0 to 0e4df9f Compare September 12, 2024 20:24

anmolnar requested changes Sep 12, 2024

View reviewed changes

ZOOKEEPER-4293: Bump netty to 4.1.113.Final, remove syncUninterruptibly

3ed97e4

Signed-off-by: Michael Edgar <medgar@redhat.com>

MikeEdgar force-pushed the ZOOKEEPER-4293 branch from 0e4df9f to 3ed97e4 Compare September 12, 2024 22:08

anmolnar approved these changes Sep 18, 2024

View reviewed changes

kezhuw approved these changes Sep 19, 2024

View reviewed changes

anmolnar merged commit 9df310a into apache:master Sep 19, 2024

anmolnar pushed a commit that referenced this pull request Sep 19, 2024

ZOOKEEPER-4293: Bump netty to 4.1.113.Final, remove syncUninterruptib…

5622988

…ly (#1917) Reviewers: anmolnar, kezhuw Author: MikeEdgar Closes #1917 from MikeEdgar/ZOOKEEPER-4293

MikeEdgar deleted the ZOOKEEPER-4293 branch September 19, 2024 19:42

kezhuw mentioned this pull request Sep 20, 2024

ZOOKEEPER-4747: Add synchronous sync to ease synchronous call chains #2068

Merged

kezhuw mentioned this pull request Sep 28, 2024

ZOOKEEPER-4824 fix CVE-2024-29025 in netty package #2156

Closed

anmolnar pushed a commit to anmolnar/zookeeper that referenced this pull request Jul 30, 2025

ZOOKEEPER-4293: Bump netty to 4.1.113.Final, remove syncUninterruptib…

acc4002

…ly (apache#1917) Reviewers: anmolnar, kezhuw Author: MikeEdgar Closes apache#1917 from MikeEdgar/ZOOKEEPER-4293

Conversation

MikeEdgar commented Aug 18, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

sonatype-lift bot commented Oct 21, 2022

Uh oh!

MikeEdgar commented Oct 21, 2022

Uh oh!

eolivelli left a comment

Choose a reason for hiding this comment

Uh oh!

eolivelli commented Dec 2, 2022

Uh oh!

MikeEdgar commented Dec 5, 2022

Uh oh!

MikeEdgar commented Apr 11, 2023

Uh oh!

MikeEdgar commented May 10, 2023

Uh oh!

kezhuw left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

kezhuw May 19, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

MikeEdgar commented Oct 12, 2023

Uh oh!

kezhuw left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

kezhuw commented Aug 26, 2024

Uh oh!

MikeEdgar commented Aug 28, 2024

Uh oh!

anmolnar commented Sep 11, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

kezhuw commented Sep 12, 2024

Uh oh!

anmolnar commented Sep 12, 2024

Uh oh!

kezhuw commented Sep 12, 2024

Uh oh!

anmolnar commented Sep 12, 2024

Uh oh!

MikeEdgar commented Sep 12, 2024

Uh oh!

anmolnar left a comment

Choose a reason for hiding this comment

Uh oh!

MikeEdgar commented Sep 12, 2024

Uh oh!

MikeEdgar commented Sep 18, 2024

Uh oh!

anmolnar left a comment

Choose a reason for hiding this comment

Uh oh!

kezhuw left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

anmolnar commented Sep 19, 2024

Uh oh!

anmolnar commented Sep 19, 2024

MikeEdgar commented Aug 18, 2022 •

edited

Loading

kezhuw May 19, 2023 •

edited

Loading

anmolnar commented Sep 11, 2024 •

edited

Loading