ZOOKEEPER-4203: Leader swallows the ZooKeeperServer.State.ERROR from Leader.LearnerCnxAcceptor in some concurrency condition #1596

functioner · 2021-02-06T21:54:03Z

The fix of ZOOKEEPER-4203 is implemented. In my local machine, it is able to pass all test cases.

…Leader.LearnerCnxAcceptor in some concurrency condition

functioner · 2021-02-06T22:56:22Z

I believe that in the CI server, multiple test cases fail due to the network connection binding issue, and the QuorumMainTest fails because the ZK snapshot is compromised by some test cases that have failed. Thus, I think this patch can be merge into master if the reviewers agree with my design.

tisonkun · 2021-02-24T13:15:12Z

retest please

tisonkun · 2021-02-24T13:15:29Z

retest please

eolivelli · 2021-02-24T13:16:44Z

@tisonkun I am sorry but the magic word does not work anymore.
Let me force a rerun manually

eolivelli · 2021-02-24T13:17:46Z

I have restarted the github actions job, but the Jenkins job is too old.
I guess you have to rebase/merge with current master and push

eolivelli

a part from CI,
I believe that this fix is not correct.

We have to deal with all of the accesses to the state field.
With this change you are only working on this method.

eolivelli

thank you @functioner for sharing your work.

I hope we will get the fix soon and see it merged to master branch

eolivelli · 2021-02-24T13:21:20Z

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

+        synchronized (stateChangeMutex) {
+            if (this.state == State.ERROR) {
+                if (state == State.RUNNING || state == State.INITIAL) {
+                    return;


we should add a relevant log in order to see if this case is happening.

Creating a test that reproduces the problem and demonstrates that this fix actually resolves the problem would be better

To add the test, do we need to consider using a fault injection tool? See ZOOKEEPER-3601 and #1135. I have provided Byteman injection script in ZOOKEEPER-4203 so it can be somehow translated into a test.

100% agree with @eolivelli on adding a LOG.warn (if not LOG.error).

For the test, I would suggest mocking and/or overriding some methods to explicitly generate the fault, if possible. I haven't tried doing so, but perhaps LearnerTest.java (which subclasses LearnerZooKeeperServer) can serve as inspiration?

100% agree with @eolivelli on adding a LOG.warn (if not LOG.error).

Okay, I will add the log later.

For the test, I would suggest mocking and/or overriding some methods to explicitly generate the fault, if possible. I haven't tried doing so, but perhaps LearnerTest.java (which subclasses LearnerZooKeeperServer) can serve as inspiration?

Okay, I will take a try.
BTW, I think introducing a fault injection tool like #1135 may make it easier to write a test for it, and is helpful for the community. Another bug I propose (#1582) also require such tool to reproduce/test. I commented at #1135 but haven't got response. Do you have any suggestion or opinion? Thank you.

Hi @functioner, I am very interested in this problem, I have written a test case, I don't konw if it can be used to test this problem.Maybe you can use it as a reference.
TestCase
Byteman btm script

if you want to use stateChangeMutex to handle concurrent access to state you have to use it at every read/write access.

Using AtomicReference is better and easier to understand.
I suggest to switch to AtomicReference and drop stateChangeMutex

tisonkun · 2021-02-24T14:11:14Z

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

@@ -189,9 +189,18 @@ public void dumpConf(PrintWriter pwriter) {
        pwriter.print(self.getQuorumVerifier().toString());
    }

+    private final Object stateChangeMutex = new Object();
+
    @Override
    protected void setState(State state) {


After a closer look I find that setState can be a single implementation in ZooKeeperServer. Just as is there. And you can apply this check as well as logging to verify as @eolivelli said.

I agree with @eolivelli that setState() has to be "careful," because ZooKeeperServerListenerImpl.notifyStopping calls it from "random" threads.

But @Tison's point still holds; it seems to me that this could be simplified by making setState() a synchronized method. Do you have a specific reason of using a separate object?

(The parent setState() does not need to be synchronized because the field is volatile.)

But @Tison's point still holds; it seems to me that this could be simplified by making setState() a synchronized method. Do you have a specific reason of using a separate object?

(The parent setState() does not need to be synchronized because the field is volatile.)

@ztzg The rationale for not making setState() a synchronized method is that if a thread is running another synchronized method of this ZooKeeperServer object for some time, it may block the setState() invoked by another thread, and this invocation may be critical.

I agree with @eolivelli that setState() has to be "careful," because ZooKeeperServerListenerImpl.notifyStopping calls it from "random" threads.

Actually, the single-node ZooKeeperServer can handle this issue with the handler:

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

Lines 779 to 789 in 0c98d1d

protected void setState(State state) {

this.state = state;

// Notify server state changes to the registered shutdown handler, if any.

if (zkShutdownHandler != null) {

zkShutdownHandler.handle(state);

} else {

LOG.debug(

"ZKShutdownHandler is not registered, so ZooKeeper server"

+ " won't take any action on ERROR or SHUTDOWN server state changes");

}

}

because it is registered at the very beginning:

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

Line 150 in 0c98d1d

zkServer.registerServerShutdownHandler(new ZooKeeperServerShutdownHandler(shutdownLatch));

This handling logic is:

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

Lines 42 to 46 in 0c98d1d

public void handle(State state) {

if (state == State.ERROR || state == State.SHUTDOWN) {

shutdownLatch.countDown();

}

}

and then

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

Lines 181 to 185 in 0c98d1d

// Watch status of ZooKeeper server. It will do a graceful shutdown

// if the server is not running or hits an internal error.

shutdownLatch.await();

shutdown();

However, in the case of QuorumZooKeeperServer, including Leader, Follower, etc., the aforementioned logic is not used.

ztzg

Hi @functioner,

Thank you for the comprehensive report, and for the patch!

I could "manually" reproduce the problem, and can confirm that your proposed change prevents the system from getting stuck.

I have left a couple of comments on the current implementation.

One thing I am wondering (which was not introduced by your code) is why we catch and continue on SaslExceptions, but "crash" on other IOExceptions? Not a major point as the server will now recover, but perhaps we could just accept that accept can fail? @eolivelli, @symat?

ztzg · 2021-03-06T15:39:58Z

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

@@ -189,9 +189,18 @@ public void dumpConf(PrintWriter pwriter) {
        pwriter.print(self.getQuorumVerifier().toString());
    }

+    private final Object stateChangeMutex = new Object();
+
    @Override
    protected void setState(State state) {


I agree with @eolivelli that setState() has to be "careful," because ZooKeeperServerListenerImpl.notifyStopping calls it from "random" threads.

But @Tison's point still holds; it seems to me that this could be simplified by making setState() a synchronized method. Do you have a specific reason of using a separate object?

(The parent setState() does not need to be synchronized because the field is volatile.)

ztzg · 2021-03-06T15:49:14Z

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

+        synchronized (stateChangeMutex) {
+            if (this.state == State.ERROR) {
+                if (state == State.RUNNING || state == State.INITIAL) {
+                    return;


100% agree with @eolivelli on adding a LOG.warn (if not LOG.error).

For the test, I would suggest mocking and/or overriding some methods to explicitly generate the fault, if possible. I haven't tried doing so, but perhaps LearnerTest.java (which subclasses LearnerZooKeeperServer) can serve as inspiration?

ztzg

(Sorry; "Approved" by accident. See my comments.)

functioner · 2021-03-06T16:52:26Z

One thing I am wondering (which was not introduced by your code) is why we catch and continue on SaslExceptions, but "crash" on other IOExceptions? Not a major point as the server will now recover, but perhaps we could just accept that accept can fail? @eolivelli, @symat?

@ztzg I think it can be explained with:

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

Lines 523 to 536 in 0c98d1d

    
           } catch (SocketException e) { 
        
               error = true; 
        
               if (stop.get()) { 
        
                   LOG.warn("Exception while shutting down acceptor.", e); 
        
               } else { 
        
                   throw e; 
        
               } 
        
           } catch (SaslException e) { 
        
               LOG.error("Exception while connecting to quorum learner", e); 
        
               error = true; 
        
           } catch (Exception e) { 
        
               error = true; 
        
               throw e; 
        
           } finally {

In the case of SaslException, the exception is not thrown again, then it will not be caught by:

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

Lines 498 to 504 in 0c98d1d

    
           } catch (Exception e) { 
        
               LOG.warn("Exception while accepting follower", e); 
        
               if (fail.compareAndSet(false, true)) { 
        
                   handleException(getName(), e); 
        
                   halt(); 
        
               } 
        
           } finally {

In this case, ZooKeeperServer.State.ERROR is not set, everything works well temporally, and the critical code

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

Line 688 in 0c98d1d

startZkServer();

finishes, so, if there is any error later, it can be detect by:

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

Line 754 in 0c98d1d

if (!this.isRunning()) {

Then, the quorum can handle it well.

However, if the IOException is not SaslException, it will be thrown again by (line 528 or 535):

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

Lines 523 to 536 in 0c98d1d

    
           } catch (SocketException e) { 
        
               error = true; 
        
               if (stop.get()) { 
        
                   LOG.warn("Exception while shutting down acceptor.", e); 
        
               } else { 
        
                   throw e; 
        
               } 
        
           } catch (SaslException e) { 
        
               LOG.error("Exception while connecting to quorum learner", e); 
        
               error = true; 
        
           } catch (Exception e) { 
        
               error = true; 
        
               throw e; 
        
           } finally {

In this case, the ZooKeeperServer.State.ERROR may be set before the critical code:

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

Line 688 in 0c98d1d

startZkServer();

Then this error state is covered by the running state. The symptom described by this issue occurs.

lanicc · 2021-03-21T10:20:39Z

I think the exception in Leader.LearnerCnxAcceptor should not be handled by zkServer, but should be handled internally by Leader.Because Acceptor and zkServer are not closely related, both Acceptor and zkServer are used as internal components of Leader, and Leader combines them to complete the function of leader.
When an exception occurs in Leader.LearnerCnxAcceptor,the error status should be fed back to Leader, that is, Leader.isRunning can find this error status.
My solution:

Leader.isRunning
Make Leader.LearnerCnxAcceptor extends ZooKeeperThread

Follower can do the same.

functioner · 2021-03-25T00:00:53Z

Follower can do the same.

@lanicc, IMO, the root problem this issue exposes is that the exception caught by ZooKeeperCriticalThread is translated into the state change in zkServer. Even if you deal with Acceptor separately in Leader. There could be other similar issues in ZooKeeperCriticalThread, affecting Leader or Follower. Either way, the logic of state change needs improvement, either in zkServer, or in Leader/Follower as you proposed. Maybe the fix you provided here is reasonable, but I think it should be a separate PR, dealing with Acceptor. The current PR should focus on improving the state change logic.

What do you think? @eolivelli @ztzg

…KEEPER-4203

functioner · 2021-11-25T03:49:10Z

I've added LOG.warn when this case is happening. You can take a look @eolivelli @ztzg
@lanicc Thanks for the test case you provide! It inspires me a lot.
I implemented a test case without using Byteman. It's basically overriding lots of methods; thanks @ztzg for the idea.
Anybody can approve the CI workflow?

functioner · 2021-11-30T05:29:54Z

@maoling Sorry to bother you. But the other guys might be busy recently. Can you help review my patch & test case? And approve the CI workflow? Thank you!

eolivelli · 2021-11-30T08:11:59Z

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

+        synchronized (stateChangeMutex) {
+            if (this.state == State.ERROR) {
+                if (state == State.RUNNING || state == State.INITIAL) {
+                    return;


if you want to use stateChangeMutex to handle concurrent access to state you have to use it at every read/write access.

Using AtomicReference is better and easier to understand.
I suggest to switch to AtomicReference and drop stateChangeMutex

functioner · 2021-12-02T01:29:29Z

@eolivelli The state check & modification within setState method should be atomic as a whole, so AtomicReference is not enough (including the updateAndGet methods and so on). Now I use synchronized for the methods which read/write state.

sonatype-lift · 2021-12-02T01:57:11Z

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

@@ -457,7 +461,7 @@ public void run() {
                CountDownLatch latch = new CountDownLatch(serverSockets.size());

                serverSockets.forEach(serverSocket ->
-                        executor.submit(new LearnerCnxAcceptorHandler(serverSocket, latch)));
+                        executor.submit(createLearnerCnxAcceptorHandler(serverSocket, latch)));


FutureReturnValueIgnored: Return value of methods returning Future must be checked. Ignoring returned Futures suppresses exceptions thrown from the code that completes the Future. (details)
(at-me in a reply with help or ignore)

@sonatype-lift ignore

I've recorded this as ignored for this pull request. If you change your mind, just comment @sonatype-lift unignore.

functioner · 2022-07-18T04:13:36Z

@eolivelli @ztzg I'm following up on whether we will merge or improve this patch soon? Thanks!

ZOOKEEPER-4203: Leader swallows the ZooKeeperServer.State.ERROR from …

0c98d1d

…Leader.LearnerCnxAcceptor in some concurrency condition

eolivelli requested changes Feb 24, 2021

View reviewed changes

tisonkun reviewed Feb 24, 2021

View reviewed changes

ztzg approved these changes Mar 6, 2021

View reviewed changes

ztzg requested changes Mar 6, 2021

View reviewed changes

functioner added 2 commits November 24, 2021 19:10

Merge branch 'master' of https://github.com/apache/zookeeper into ZOO…

eccda87

…KEEPER-4203

add log and test

544fd98

functioner requested review from ztzg and eolivelli November 29, 2021 18:57

eolivelli requested changes Nov 30, 2021

View reviewed changes

use synchronized methods to protect state

0657332

functioner requested a review from eolivelli December 2, 2021 01:30

sonatype-lift bot reviewed Dec 2, 2021

View reviewed changes

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

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

ZOOKEEPER-4203: Leader swallows the ZooKeeperServer.State.ERROR from Leader.LearnerCnxAcceptor in some concurrency condition #1596

ZOOKEEPER-4203: Leader swallows the ZooKeeperServer.State.ERROR from Leader.LearnerCnxAcceptor in some concurrency condition #1596

functioner commented Feb 6, 2021

functioner commented Feb 6, 2021

tisonkun commented Feb 24, 2021

tisonkun commented Feb 24, 2021

eolivelli commented Feb 24, 2021

eolivelli commented Feb 24, 2021

eolivelli left a comment

eolivelli left a comment

eolivelli Feb 24, 2021

functioner Feb 24, 2021 •

edited

ztzg Mar 6, 2021

functioner Mar 6, 2021

lanicc Mar 15, 2021

eolivelli Nov 30, 2021

tisonkun Feb 24, 2021

ztzg Mar 6, 2021

functioner Mar 6, 2021

functioner Mar 6, 2021

ztzg left a comment

ztzg Mar 6, 2021

ztzg Mar 6, 2021

ztzg left a comment

functioner commented Mar 6, 2021 •

edited

lanicc commented Mar 21, 2021

functioner commented Mar 25, 2021

functioner commented Nov 25, 2021

functioner commented Nov 30, 2021

eolivelli Nov 30, 2021

functioner commented Dec 2, 2021 •

edited

sonatype-lift bot Dec 2, 2021

functioner Dec 2, 2021

sonatype-lift bot Dec 2, 2021

functioner commented Jul 18, 2022

	protected void setState(State state) {
	this.state = state;
	// Notify server state changes to the registered shutdown handler, if any.
	if (zkShutdownHandler != null) {
	zkShutdownHandler.handle(state);
	} else {
	LOG.debug(
	"ZKShutdownHandler is not registered, so ZooKeeper server"
	+ " won't take any action on ERROR or SHUTDOWN server state changes");
	}
	}

	public void handle(State state) {
	if (state == State.ERROR \|\| state == State.SHUTDOWN) {
	shutdownLatch.countDown();
	}
	}

	// Watch status of ZooKeeper server. It will do a graceful shutdown
	// if the server is not running or hits an internal error.
	shutdownLatch.await();

	shutdown();

ZOOKEEPER-4203: Leader swallows the ZooKeeperServer.State.ERROR from Leader.LearnerCnxAcceptor in some concurrency condition #1596

Are you sure you want to change the base?

ZOOKEEPER-4203: Leader swallows the ZooKeeperServer.State.ERROR from Leader.LearnerCnxAcceptor in some concurrency condition #1596

Conversation

functioner commented Feb 6, 2021

functioner commented Feb 6, 2021

tisonkun commented Feb 24, 2021

tisonkun commented Feb 24, 2021

eolivelli commented Feb 24, 2021

eolivelli commented Feb 24, 2021

eolivelli left a comment

Choose a reason for hiding this comment

eolivelli left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

functioner Feb 24, 2021 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ztzg left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ztzg left a comment

Choose a reason for hiding this comment

functioner commented Mar 6, 2021 • edited

lanicc commented Mar 21, 2021

functioner commented Mar 25, 2021

functioner commented Nov 25, 2021

functioner commented Nov 30, 2021

Choose a reason for hiding this comment

functioner commented Dec 2, 2021 • edited

sonatype-lift bot Dec 2, 2021

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sonatype-lift bot Dec 2, 2021

Choose a reason for hiding this comment

functioner commented Jul 18, 2022

functioner Feb 24, 2021 •

edited

functioner commented Mar 6, 2021 •

edited

functioner commented Dec 2, 2021 •

edited