Skip to content

Commit 6c10bb7

Browse files
ydashydash
authored
Merge pull request #102 from lerna-stack/check-the-loglevel-is-enabled
Evaluate log operations only when the log level is enabled
2 parents ea74936 + d4e01bb commit 6c10bb7

File tree

12 files changed

+165
-134
lines changed

12 files changed

+165
-134
lines changed

‎src/main/scala/lerna/akka/entityreplication/ReplicationActor.scala‎

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -59,7 +59,8 @@ trait ReplicationActor[StateData] extends Actor with Stash with akka.lerna.Stash
5959
case RecoveryTimeout =>
6060
// to restart
6161
// TODO: BackoffSupervisor を使ってカスケード障害を回避する
62-
log.info("Entity (name: {}) recovering timed out. It will be retried later.", self.path.name)
62+
if (log.isInfoEnabled)
63+
log.info("Entity (name: {}) recovering timed out. It will be retried later.", self.path.name)
6364
throw EntityRecoveryTimeoutException(self.path)
6465

6566
case RecoveryState(logEntries, maybeSnapshot) =>
@@ -88,7 +89,7 @@ trait ReplicationActor[StateData] extends Actor with Stash with akka.lerna.Stash
8889
receive.applyOrElse[Any, Unit](
8990
command,
9091
command => {
91-
log.warning("unhandled {} by receiveCommand", command)
92+
if (log.isWarningEnabled) log.warning("unhandled {} by receiveCommand", command)
9293
},
9394
)
9495

@@ -161,7 +162,7 @@ trait ReplicationActor[StateData] extends Actor with Stash with akka.lerna.Stash
161162
receiveReplica.applyOrElse[Any, Unit](
162163
event,
163164
event => {
164-
log.warning("unhandled {} by receiveReplica", event)
165+
if (log.isWarningEnabled) log.warning("unhandled {} by receiveReplica", event)
165166
},
166167
)
167168
lastAppliedLogEntryIndex = logEntryIndex

‎src/main/scala/lerna/akka/entityreplication/ReplicationRegion.scala‎

Lines changed: 11 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -100,7 +100,7 @@ private[entityreplication] class ReplicationRegion(
100100
val decide = super.supervisorStrategy.decider(e)
101101
decide match {
102102
case directive =>
103-
log.error(e, s"$directive")
103+
if (log.isErrorEnabled) log.error(e, "{}", directive)
104104
}
105105
decide
106106
}
@@ -237,20 +237,21 @@ private[entityreplication] class ReplicationRegion(
237237
)
238238
handleRoutingCommand(DeliverSomewhere(Command(message)))
239239
} else {
240-
log.warning("The message [{}] was dropped because its shard ID could not be extracted", message)
240+
if (log.isWarningEnabled)
241+
log.warning("The message [{}] was dropped because its shard ID could not be extracted", message)
241242
}
242243
}
243244

244245
private[this] def updateState(): Unit = {
245246
val availableRegions = regions.filter { case (_, members) => members.nonEmpty }
246247
stickyRoutingRouter =
247248
stickyRoutingRouter.withRoutees(availableRegions.keys.map(i => ActorRefRoutee(shardingRouters(i))).toVector)
248-
log.info("Available cluster members changed: {}", availableRegions)
249+
if (log.isInfoEnabled) log.info("Available cluster members changed: {}", availableRegions)
249250
// 一度 open になったら、その後は転送先のメンバーを増減させるだけ
250251
// 想定以上にメッセージが遅延して到着することを避けるため、メンバーが不足していたとしてもメッセージを stash しない
251252
if (availableRegions.size >= settings.raftSettings.quorumSize) {
252253
context.become(open)
253-
log.debug("=== {} will be open ===", classOf[ReplicationRegion].getSimpleName)
254+
if (log.isDebugEnabled) log.debug("=== {} will be open ===", classOf[ReplicationRegion].getSimpleName)
254255
unstashAll()
255256
}
256257
}
@@ -290,11 +291,12 @@ private[entityreplication] class ReplicationRegion(
290291
private[this] def memberIndexOf(member: Member): Option[MemberIndex] = {
291292
val maybeMemberIndex = allMemberIndexes.find(i => member.roles.contains(i.role))
292293
if (maybeMemberIndex.isEmpty) {
293-
log.warning(
294-
"Member {} has no any role of MemberIndexes ({}). This member will be ignored",
295-
member,
296-
allMemberIndexes,
297-
)
294+
if (log.isWarningEnabled)
295+
log.warning(
296+
"Member {} has no any role of MemberIndexes ({}). This member will be ignored",
297+
member,
298+
allMemberIndexes,
299+
)
298300
}
299301
maybeMemberIndex
300302
}

‎src/main/scala/lerna/akka/entityreplication/raft/Candidate.scala‎

Lines changed: 8 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,8 @@ private[raft] trait Candidate { this: RaftActor =>
1212
def candidateBehavior: Receive = {
1313

1414
case ElectionTimeout =>
15-
log.info("[Candidate] Election timeout at {}. Retrying leader election.", currentData.currentTerm)
15+
if (log.isInfoEnabled)
16+
log.info("[Candidate] Election timeout at {}. Retrying leader election.", currentData.currentTerm)
1617
val newTerm = currentData.currentTerm.next()
1718
cancelElectionTimeoutTimer()
1819
broadcast(
@@ -51,7 +52,7 @@ private[raft] trait Candidate { this: RaftActor =>
5152
request match {
5253

5354
case RequestVote(_, term, candidate, _, _) if term == currentData.currentTerm && candidate == selfMemberIndex =>
54-
log.debug(s"=== [Candidate] accept self RequestVote ===")
55+
if (log.isDebugEnabled) log.debug("=== [Candidate] accept self RequestVote ===")
5556
applyDomainEvent(Voted(term, selfMemberIndex)) { _ =>
5657
sender() ! RequestVoteAccepted(term, selfMemberIndex)
5758
}
@@ -60,15 +61,15 @@ private[raft] trait Candidate { this: RaftActor =>
6061
if term.isNewerThan(
6162
currentData.currentTerm,
6263
) && lastLogTerm >= currentData.replicatedLog.lastLogTerm && lastLogIndex >= currentData.replicatedLog.lastLogIndex =>
63-
log.debug(s"=== [Candidate] accept RequestVote($term, $otherCandidate) ===")
64+
if (log.isDebugEnabled) log.debug("=== [Candidate] accept RequestVote({}, {}) ===", term, otherCandidate)
6465
cancelElectionTimeoutTimer()
6566
applyDomainEvent(Voted(term, otherCandidate)) { domainEvent =>
6667
sender() ! RequestVoteAccepted(domainEvent.term, selfMemberIndex)
6768
become(Follower)
6869
}
6970

7071
case request: RequestVote =>
71-
log.debug(s"=== [Candidate] deny $request ===")
72+
if (log.isDebugEnabled) log.debug("=== [Candidate] deny {} ===", request)
7273
if (request.term.isNewerThan(currentData.currentTerm)) {
7374
cancelElectionTimeoutTimer()
7475
applyDomainEvent(DetectedNewTerm(request.term)) { _ =>
@@ -90,7 +91,7 @@ private[raft] trait Candidate { this: RaftActor =>
9091
case accepted: RequestVoteAccepted if accepted.term == currentData.currentTerm =>
9192
cancelElectionTimeoutTimer()
9293
applyDomainEvent(AcceptedRequestVote(accepted.sender)) { _ =>
93-
log.debug("=== [Candidate] accept for {} ===", accepted.sender)
94+
if (log.isDebugEnabled) log.debug("=== [Candidate] accept for {} ===", accepted.sender)
9495
if (currentData.gotAcceptionMajorityOf(numberOfMembers)) {
9596
become(Leader)
9697
} else {
@@ -128,7 +129,7 @@ private[raft] trait Candidate { this: RaftActor =>
128129

129130
case appendEntries: AppendEntries =>
130131
if (currentData.hasMatchLogEntry(appendEntries.prevLogIndex, appendEntries.prevLogTerm)) {
131-
log.debug(s"=== [Candidate] append $appendEntries ===")
132+
if (log.isDebugEnabled) log.debug("=== [Candidate] append {} ===", appendEntries)
132133
cancelElectionTimeoutTimer()
133134
if (appendEntries.entries.isEmpty && appendEntries.term == currentData.currentTerm) {
134135
// do not persist event when no need
@@ -154,7 +155,7 @@ private[raft] trait Candidate { this: RaftActor =>
154155
}
155156
}
156157
} else { // prevLogIndex と prevLogTerm がマッチするエントリが無かった
157-
log.debug(s"=== [Candidate] could not append $appendEntries ===")
158+
if (log.isDebugEnabled) log.debug("=== [Candidate] could not append {} ===", appendEntries)
158159
cancelElectionTimeoutTimer()
159160
if (appendEntries.term == currentData.currentTerm) {
160161
applyDomainEvent(DetectedLeaderMember(appendEntries.leader)) { _ =>

‎src/main/scala/lerna/akka/entityreplication/raft/Follower.scala‎

Lines changed: 10 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -14,9 +14,9 @@ private[raft] trait Follower { this: RaftActor =>
1414

1515
case ElectionTimeout =>
1616
if (currentData.leaderMember.isEmpty) {
17-
log.debug(s"=== [Follower] election timeout ===")
17+
if (log.isDebugEnabled) log.debug("=== [Follower] election timeout ===")
1818
} else {
19-
log.warning("[{}] election timeout. Leader will be changed", currentState)
19+
if (log.isWarningEnabled) log.warning("[{}] election timeout. Leader will be changed", currentState)
2020
}
2121
requestVote(currentData)
2222

@@ -42,12 +42,12 @@ private[raft] trait Follower { this: RaftActor =>
4242
request match {
4343

4444
case request: RequestVote if request.term.isOlderThan(currentData.currentTerm) =>
45-
log.debug(s"=== [Follower] deny $request ===")
45+
if (log.isDebugEnabled) log.debug("=== [Follower] deny {} ===", request)
4646
sender() ! RequestVoteDenied(currentData.currentTerm)
4747

4848
case request: RequestVote
4949
if request.lastLogTerm < currentData.replicatedLog.lastLogTerm || request.lastLogIndex < currentData.replicatedLog.lastLogIndex =>
50-
log.debug(s"=== [Follower] deny $request ===")
50+
if (log.isDebugEnabled) log.debug("=== [Follower] deny {} ===", request)
5151
if (request.term.isNewerThan(currentData.currentTerm)) {
5252
applyDomainEvent(DetectedNewTerm(request.term)) { _ =>
5353
sender() ! RequestVoteDenied(currentData.currentTerm)
@@ -57,23 +57,23 @@ private[raft] trait Follower { this: RaftActor =>
5757
}
5858

5959
case request: RequestVote if request.term.isNewerThan(currentData.currentTerm) =>
60-
log.debug(s"=== [Follower] accept $request ===")
60+
if (log.isDebugEnabled) log.debug("=== [Follower] accept {} ===", request)
6161
cancelElectionTimeoutTimer()
6262
applyDomainEvent(Voted(request.term, request.candidate)) { domainEvent =>
6363
sender() ! RequestVoteAccepted(domainEvent.term, selfMemberIndex)
6464
resetElectionTimeoutTimer()
6565
}
6666

6767
case request: RequestVote if !currentData.alreadyVotedOthers(request.candidate) =>
68-
log.debug(s"=== [Follower] accept $request ===")
68+
if (log.isDebugEnabled) log.debug("=== [Follower] accept {} ===", request)
6969
cancelElectionTimeoutTimer()
7070
applyDomainEvent(Voted(request.term, request.candidate)) { domainEvent =>
7171
sender() ! RequestVoteAccepted(domainEvent.term, selfMemberIndex)
7272
resetElectionTimeoutTimer()
7373
}
7474

7575
case request: RequestVote =>
76-
log.debug(s"=== [Follower] deny $request ===")
76+
if (log.isDebugEnabled) log.debug("=== [Follower] deny {} ===", request)
7777
sender() ! RequestVoteDenied(currentData.currentTerm)
7878
}
7979

@@ -85,7 +85,7 @@ private[raft] trait Follower { this: RaftActor =>
8585

8686
case appendEntries: AppendEntries =>
8787
if (currentData.hasMatchLogEntry(appendEntries.prevLogIndex, appendEntries.prevLogTerm)) {
88-
log.debug(s"=== [Follower] append $appendEntries ===")
88+
if (log.isDebugEnabled) log.debug("=== [Follower] append {} ===", appendEntries)
8989
cancelElectionTimeoutTimer()
9090
if (appendEntries.entries.isEmpty && appendEntries.term == currentData.currentTerm) {
9191
// do not persist event when no need
@@ -111,7 +111,7 @@ private[raft] trait Follower { this: RaftActor =>
111111
}
112112
}
113113
} else { // prevLogIndex と prevLogTerm がマッチするエントリが無かった
114-
log.debug(s"=== [Follower] could not append $appendEntries ===")
114+
if (log.isDebugEnabled) log.debug("=== [Follower] could not append {} ===", appendEntries)
115115
cancelElectionTimeoutTimer()
116116
if (appendEntries.term == currentData.currentTerm) {
117117
applyDomainEvent(DetectedLeaderMember(appendEntries.leader)) { _ =>
@@ -132,7 +132,7 @@ private[raft] trait Follower { this: RaftActor =>
132132
private[this] def handleCommand(command: Command): Unit =
133133
(currentData.leaderMember, currentData.votedFor) match {
134134
case (Some(leader), _) =>
135-
log.debug(s"=== [Follower] forward $command to $leader ===")
135+
if (log.isDebugEnabled) log.debug("=== [Follower] forward {} to {} ===", command, leader)
136136
region forward ReplicationRegion.DeliverTo(leader, ForwardedCommand(command))
137137
case (None, _) =>
138138
stash()

‎src/main/scala/lerna/akka/entityreplication/raft/Leader.scala‎

Lines changed: 10 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -48,15 +48,15 @@ private[raft] trait Leader { this: RaftActor =>
4848
if term.isNewerThan(
4949
currentData.currentTerm,
5050
) && lastLogTerm >= currentData.replicatedLog.lastLogTerm && lastLogIndex >= currentData.replicatedLog.lastLogIndex =>
51-
log.debug(s"=== [Leader] accept RequestVote($term, $candidate) ===")
51+
if (log.isDebugEnabled) log.debug("=== [Leader] accept RequestVote({}, {}) ===", term, candidate)
5252
cancelHeartbeatTimeoutTimer()
5353
applyDomainEvent(Voted(term, candidate)) { domainEvent =>
5454
sender() ! RequestVoteAccepted(domainEvent.term, selfMemberIndex)
5555
become(Follower)
5656
}
5757

5858
case request: RequestVote =>
59-
log.debug(s"=== [Leader] deny $request ===")
59+
if (log.isDebugEnabled) log.debug("=== [Leader] deny {} ===", request)
6060
if (request.term.isNewerThan(currentData.currentTerm)) {
6161
cancelHeartbeatTimeoutTimer()
6262
applyDomainEvent(DetectedNewTerm(request.term)) { _ =>
@@ -88,7 +88,7 @@ private[raft] trait Leader { this: RaftActor =>
8888
case appendEntries: AppendEntries if appendEntries.term.isNewerThan(currentData.currentTerm) =>
8989
if (currentData.hasMatchLogEntry(appendEntries.prevLogIndex, appendEntries.prevLogTerm)) {
9090
cancelHeartbeatTimeoutTimer()
91-
log.debug(s"=== [Leader] append $appendEntries ===")
91+
if (log.isDebugEnabled) log.debug("=== [Leader] append {} ===", appendEntries)
9292
applyDomainEvent(AppendedEntries(appendEntries.term, appendEntries.entries, appendEntries.prevLogIndex)) {
9393
domainEvent =>
9494
applyDomainEvent(FollowedLeaderCommit(appendEntries.leader, appendEntries.leaderCommit)) { _ =>
@@ -101,7 +101,7 @@ private[raft] trait Leader { this: RaftActor =>
101101
}
102102
}
103103
} else { // prevLogIndex と prevLogTerm がマッチするエントリが無かった
104-
log.debug(s"=== [Leader] could not append $appendEntries ===")
104+
if (log.isDebugEnabled) log.debug("=== [Leader] could not append {} ===", appendEntries)
105105
cancelHeartbeatTimeoutTimer()
106106
applyDomainEvent(DetectedNewTerm(appendEntries.term)) { domainEvent =>
107107
applyDomainEvent(DetectedLeaderMember(appendEntries.leader)) { _ =>
@@ -131,7 +131,8 @@ private[raft] trait Leader { this: RaftActor =>
131131
}
132132

133133
case succeeded: AppendEntriesSucceeded if succeeded.term.isNewerThan(currentData.currentTerm) =>
134-
log.warning("Unexpected message received: {} (currentTerm: {})", succeeded, currentData.currentTerm)
134+
if (log.isWarningEnabled)
135+
log.warning("Unexpected message received: {} (currentTerm: {})", succeeded, currentData.currentTerm)
135136

136137
case succeeded: AppendEntriesSucceeded if succeeded.term.isOlderThan(currentData.currentTerm) =>
137138
// ignore: Follower always synchronizes Term before replying, so it does not happen normally
@@ -163,7 +164,8 @@ private[raft] trait Leader { this: RaftActor =>
163164
applyDomainEvent(SucceededAppendEntries(follower, succeeded.dstLatestSnapshotLastLogLogIndex)) { _ => }
164165

165166
case succeeded: InstallSnapshotSucceeded if succeeded.term.isNewerThan(currentData.currentTerm) =>
166-
log.warning("Unexpected message received: {} (currentTerm: {})", succeeded, currentData.currentTerm)
167+
if (log.isWarningEnabled)
168+
log.warning("Unexpected message received: {} (currentTerm: {})", succeeded, currentData.currentTerm)
167169

168170
case succeeded: InstallSnapshotSucceeded =>
169171
assert(succeeded.term.isOlderThan(currentData.currentTerm))
@@ -205,7 +207,7 @@ private[raft] trait Leader { this: RaftActor =>
205207
// ignore: no-op replication when become leader
206208

207209
case ReplicationSucceeded(unknownEvent, _, _) =>
208-
log.warning("unknown event: {}", unknownEvent)
210+
if (log.isWarningEnabled) log.warning("unknown event: {}", unknownEvent)
209211
}
210212

211213
private[this] def startEntityPassivationProcess(entityPath: ActorPath, stopMessage: Any): Unit = {
@@ -264,7 +266,7 @@ private[raft] trait Leader { this: RaftActor =>
264266
),
265267
)
266268
}
267-
log.debug(s"=== [Leader] publish ${messages.mkString(",")} to $memberIndex ===")
269+
if (log.isDebugEnabled) log.debug("=== [Leader] publish {} to {} ===", messages.mkString(","), memberIndex)
268270
messages.foreach(region ! ReplicationRegion.DeliverTo(memberIndex, _))
269271
}
270272
}

0 commit comments

Comments
 (0)