zookeeper-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From h...@apache.org
Subject [zookeeper] branch master updated: ZOOKEEPER-3479: Logging false leader election times
Date Fri, 02 Aug 2019 18:09:02 GMT
This is an automated email from the ASF dual-hosted git repository.

hanm pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/zookeeper.git


The following commit(s) were added to refs/heads/master by this push:
     new 3882a01  ZOOKEEPER-3479: Logging false leader election times
3882a01 is described below

commit 3882a0171f91280bf1adbbd4ffaeb17cb5131316
Author: Karolos Antoniadis <karolos@gmail.com>
AuthorDate: Fri Aug 2 11:08:47 2019 -0700

    ZOOKEEPER-3479: Logging false leader election times
    
    See https://issues.apache.org/jira/browse/ZOOKEEPER-3479 here for the issue.
    
    The problem is that the logged leader election times are much smaller than in reality.
For example, we have log files that contain the following lines:
    ```
    2019-07-31 00:57:31,852 [myid:1] - WARN [QuorumPeer[myid=1](plain=/0.0.0.0:2791)(secure=disabled):QuorumPeer1318]
- PeerState set to LOOKING
    2019-07-31 00:57:31,853 [myid:1] - INFO [QuorumPeer[myid=1](plain=/0.0.0.0:2791)(secure=disabled):QuorumPeer1193]
- LOOKING
    2019-07-31 00:57:31,853 [myid:1] - INFO [QuorumPeer[myid=1](plain=/0.0.0.0:2791)(secure=disabled):FastLeaderElection885]
- New election. My id = 1, proposed zxid=0x100000001
    [...]
    2019-07-31 00:57:32,272 [myid:1] - INFO [QuorumPeer[myid=1](plain=/0.0.0.0:2791)(secure=disabled):Follower69]
- FOLLOWING - LEADER ELECTION TOOK - 1 MS
    ```
    Leader election took more than 400ms, not 1ms!
    
    The reason this logging bug exists has to do with this [line](https://github.com/apache/zookeeper/blob/master/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java#L1402)
in `QuorumPeer`. The computation of the leader election time starts inside [`FastLeaderElection.lookForLeader`
](https://github.com/apache/zookeeper/blob/master/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/FastLeaderElection.java#L915)
where `start_fle` is set. After a [...]
    
    Furthermore, if we remove the problematic [line](https://github.com/apache/zookeeper/blob/master/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java#L1402),
then there is no reason to check whether `start_fle == 0` in [`FastLeaderElection`](https://github.com/apache/zookeeper/blob/master/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/FastLeaderElection.java#L914),
since `start_fle` is always `0` at that point. I'm not sure if this `if`  [...]
    
    Author: foo bar <karolos@gmail.com>
    
    Reviewers: Michael Han <hanm@apache.org>, Allan Lyu <fangmin@apache.org>
    
    Closes #1031 from insumity/ZOOKEEPER-3479
---
 .../java/org/apache/zookeeper/server/quorum/FastLeaderElection.java  | 5 ++---
 .../src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java | 1 -
 2 files changed, 2 insertions(+), 4 deletions(-)

diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/FastLeaderElection.java
b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/FastLeaderElection.java
index 6dacc49..42fed41 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/FastLeaderElection.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/FastLeaderElection.java
@@ -911,9 +911,8 @@ public class FastLeaderElection implements Election {
             LOG.warn("Failed to register with JMX", e);
             self.jmxLeaderElectionBean = null;
         }
-        if (self.start_fle == 0) {
-           self.start_fle = Time.currentElapsedTime();
-        }
+
+        self.start_fle = Time.currentElapsedTime();
         try {
             Map<Long, Vote> recvset = new HashMap<Long, Vote>();
 
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java
b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java
index 521f6d4..ce794d1 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeer.java
@@ -1399,7 +1399,6 @@ public class QuorumPeer extends ZooKeeperThread implements QuorumStats.Provider
                     }
                     break;
                 }
-                start_fle = Time.currentElapsedTime();
             }
         } finally {
             LOG.warn("QuorumPeer main thread exited");


Mime
View raw message