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 <karo...@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 <karo...@gmail.com>
Reviewers: Michael Han <h...@apache.org>, Allan Lyu <fang...@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");
