Uploaded image for project: 'ZooKeeper'
  1. ZooKeeper
  2. ZOOKEEPER-2550

FollowerResyncConcurrencyTest failed in ZooKeeper 3.3.3

    Details

    • Type: Bug
    • Status: Open
    • Priority: Blocker
    • Resolution: Unresolved
    • Affects Version/s: 3.3.3
    • Fix Version/s: None
    • Component/s: leaderElection, quorum, server, tests
    • Labels:
    • Environment:

      Windows 10,
      Java 1.8.0,
      IDEA 2016.1.4,
      JUnit 4.8.1

      Description

      I'm studying on the Test of ZooKeeper 3.3.3 but got a test failure when I run testResyncBySnapThenDiffAfterFollowerCrashes in FollowerResyncConcurrencyTest.java.

      2016-09-05 13:57:35,072 - INFO [main:QuorumBase@307] - FINISHED testResyncBySnapThenDiffAfterFollowerCrashes

      java.util.concurrent.TimeoutException: Did not connect

      at org.apache.zookeeper.test.ClientBase$CountdownWatcher.waitForConnected(ClientBase.java:119)
      at org.apache.zookeeper.test.FollowerResyncConcurrencyTest.testResyncBySnapThenDiffAfterFollowerCrashes(FollowerResyncConcurrencyTest.java:95)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:497)
      at junit.framework.TestCase.runTest(TestCase.java:168)
      at junit.framework.TestCase.runBare(TestCase.java:134)
      at junit.framework.TestResult$1.protect(TestResult.java:110)
      at junit.framework.TestResult.runProtected(TestResult.java:128)
      at junit.framework.TestResult.run(TestResult.java:113)
      at junit.framework.TestCase.run(TestCase.java:124)
      at junit.framework.TestSuite.runTest(TestSuite.java:232)
      at junit.framework.TestSuite.run(TestSuite.java:227)
      at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83)
      at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
      at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:119)
      at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:42)
      at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234)
      at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:497)
      at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)

      Which happened in FollowerResyncConcurrencyTest.java at line 92.

      index = (index == 1) ? 2 : 1;
      qu.shutdown(index);
      final ZooKeeper zk3 = new DisconnectableZooKeeper("127.0.0.1:" + qu.getPeer(3).peer.getClientPort(), 1000,watcher3);
      watcher3.waitForConnected(CONNECTION_TIMEOUT);
      zk3.create("/mybar", null, ZooDefs.Ids.OPEN_ACL_UNSAFE, CreateMode.EPHEMERAL_SEQUENTIAL);

      I checked the Log Message, and I guess it is probably because of the following ERROR (marked as blue):

      2016-09-05 13:56:54,928 - INFO [main-SendThread():ClientCnxn$SendThread@1041] - Opening socket connection to server /127.0.0.1:11237
      2016-09-05 13:56:54,930 - INFO [main-SendThread(127.0.0.1:11237):ClientCnxn$SendThread@949] - Socket connection established to 127.0.0.1/127.0.0.1:11237, initiating session
      2016-09-05 13:56:54,930 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11237:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:33566
      2016-09-05 13:56:54,957 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11237:NIOServerCnxn@777] - Client attempting to establish new session at /127.0.0.1:33566

      2016-09-05 13:56:55,000 - INFO [SyncThread:3:FileTxnLog@197] - Creating new log file: log.100000001
      2016-09-05 13:56:55,000 - WARN [QuorumPeer:/0:0:0:0:0:0:0:0:11235:Follower@116] - Got zxid 0x100000001 expected 0x1
      2016-09-05 13:56:55,000 - INFO [SyncThread:2:FileTxnLog@197] - Creating new log file: log.100000001
      2016-09-05 13:56:55,078 - ERROR [CommitProcessor:3:CommitProcessor@146] - Unexpected exception causing CommitProcessor to exit
      java.lang.AssertionError
      at org.apache.zookeeper.jmx.MBeanRegistry.register(MBeanRegistry.java:66)
      at org.apache.zookeeper.server.NIOServerCnxn.finishSessionInit(NIOServerCnxn.java:1552)
      at org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalRequestProcessor.java:183)
      at org.apache.zookeeper.server.quorum.Leader$ToBeAppliedRequestProcessor.processRequest(Leader.java:540)
      at org.apache.zookeeper.server.quorum.CommitProcessor.run(CommitProcessor.java:73)
      2016-09-05 13:56:55,078 - INFO [CommitProcessor:3:CommitProcessor@148] - CommitProcessor exited loop!

      2016-09-05 13:56:55,931 - INFO [main-SendThread(127.0.0.1:11237):ClientCnxn$SendThread@1157] - Client session timed out, have not heard from server in 1001ms for sessionid 0x0, closing socket connection and attempting reconnect
      2016-09-05 13:56:58,035 - INFO [main-SendThread(127.0.0.1:11237):ClientCnxn$SendThread@1041] - Opening socket connection to server 127.0.0.1/127.0.0.1:11237
      2016-09-05 13:56:58,036 - INFO [main-SendThread(127.0.0.1:11237):ClientCnxn$SendThread@949] - Socket connection established to 127.0.0.1/127.0.0.1:11237, initiating session

      I'll very appreciate it if I can get some help from you genius people.
      Thanks.

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              yinkang KangYin
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated: