From 1b1360ac337d23b9a586f62616eb278c3065eef0 Mon Sep 17 00:00:00 2001 From: Robert Varga Date: Wed, 24 Jan 2018 02:39:50 +0100 Subject: [PATCH 1/1] Measure follower activity in nanoseconds We get more precise tracking and also fewer conversions on the fast path. Change-Id: Iea9700bce0b2c75ff26447f2b65022dbfb8dda37 Signed-off-by: Robert Varga --- .../cluster/raft/FollowerLogInformation.java | 6 +++--- .../controller/cluster/raft/RaftActor.java | 3 ++- .../cluster/raft/behaviors/AbstractLeader.java | 12 ++++++------ 3 files changed, 11 insertions(+), 10 deletions(-) diff --git a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformation.java b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformation.java index 9fd2edcb0e..3952b386b2 100644 --- a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformation.java +++ b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformation.java @@ -215,10 +215,10 @@ public final class FollowerLogInformation { /** * Returns the time since the last activity occurred for the follower. * - * @return time in milliseconds since the last activity from the follower. + * @return time in nanoseconds since the last activity from the follower. */ - public long timeSinceLastActivity() { - return stopwatch.elapsed(TimeUnit.MILLISECONDS); + public long nanosSinceLastActivity() { + return stopwatch.elapsed(TimeUnit.NANOSECONDS); } /** diff --git a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/RaftActor.java b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/RaftActor.java index 967a8fb9b3..f9099a7b81 100755 --- a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/RaftActor.java +++ b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/RaftActor.java @@ -484,7 +484,8 @@ public abstract class RaftActor extends AbstractUntypedPersistentActor { for (String id: followerIds) { final FollowerLogInformation info = leader.getFollower(id); followerInfoList.add(new FollowerInfo(id, info.getNextIndex(), info.getMatchIndex(), - info.isFollowerActive(), DurationFormatUtils.formatDurationHMS(info.timeSinceLastActivity()), + info.isFollowerActive(), DurationFormatUtils.formatDurationHMS( + TimeUnit.NANOSECONDS.toMillis(info.nanosSinceLastActivity())), context.getPeerInfo(info.getId()).isVoting())); } diff --git a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/behaviors/AbstractLeader.java b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/behaviors/AbstractLeader.java index ba998d3295..15dbd74d01 100644 --- a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/behaviors/AbstractLeader.java +++ b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/behaviors/AbstractLeader.java @@ -216,11 +216,11 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior { return this; } - if (followerLogInformation.timeSinceLastActivity() - > context.getConfigParams().getElectionTimeOutInterval().toMillis()) { + final long lastActivityNanos = followerLogInformation.nanosSinceLastActivity(); + if (lastActivityNanos > context.getConfigParams().getElectionTimeOutInterval().toNanos()) { log.warn("{} : handleAppendEntriesReply delayed beyond election timeout, " + "appendEntriesReply : {}, timeSinceLastActivity : {}, lastApplied : {}, commitIndex : {}", - logName(), appendEntriesReply, followerLogInformation.timeSinceLastActivity(), + logName(), appendEntriesReply, TimeUnit.NANOSECONDS.toMillis(lastActivityNanos), context.getLastApplied(), context.getCommitIndex()); } @@ -629,14 +629,14 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior { } } - protected void sendAppendEntries(final long timeSinceLastActivityInterval, final boolean isHeartbeat) { + protected void sendAppendEntries(final long timeSinceLastActivityIntervalNanos, final boolean isHeartbeat) { // Send an AppendEntries to all followers for (Entry e : followerToLog.entrySet()) { final String followerId = e.getKey(); final FollowerLogInformation followerLogInformation = e.getValue(); // This checks helps not to send a repeat message to the follower if (!followerLogInformation.isFollowerActive() - || followerLogInformation.timeSinceLastActivity() >= timeSinceLastActivityInterval) { + || followerLogInformation.nanosSinceLastActivity() >= timeSinceLastActivityIntervalNanos) { sendUpdatesToFollower(followerId, followerLogInformation, true, isHeartbeat); } } @@ -949,7 +949,7 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior { private void sendHeartBeat() { if (!followerToLog.isEmpty()) { log.trace("{}: Sending heartbeat", logName()); - sendAppendEntries(context.getConfigParams().getHeartBeatInterval().toMillis(), true); + sendAppendEntries(context.getConfigParams().getHeartBeatInterval().toNanos(), true); appendEntriesMessageSlicer.checkExpiredSlicedMessageState(); } -- 2.36.6