Improve logging in LeaderChecker#78883
Merged
DaveCTurner merged 1 commit intoOct 15, 2021
Merged
Conversation
Today if the `LeaderChecker` decides it's time to restart discovery then
we log a verbose and confusing message that looks something like this:
[instance-0000000006] master node [...] failed, restarting discovery
org.elasticsearch.ElasticsearchException: node [...] failed [3] consecutive checks
at org.elasticsearch.cluster.coordination.LeaderChecker$CheckScheduler$1.handleException(LeaderChecker.java:275) ~[elasticsearch-7.14.1.jar:7.14.1]
...
at java.lang.Thread.run(Thread.java:831) [?:?]
Caused by: org.elasticsearch.transport.RemoteTransportException: [...][internal:coordination/fault_detection/leader_check]
Caused by: org.elasticsearch.cluster.coordination.CoordinationStateRejectedException: rejecting leader check since [...] has been removed from the cluster
at org.elasticsearch.cluster.coordination.LeaderChecker.handleLeaderCheck(LeaderChecker.java:181) ~[elasticsearch-7.14.1.jar:7.14.1]
...
at java.lang.Thread.run(Thread.java:831) ~[?:?]
There's quite a few problems with this:
- We use `DiscoveryNode#toString` which is far too chatty.
- There's basically nothing useful in these stack traces.
- It's easy to miss the `RemoteTransportException` in the middle.
- It's also easy to miss the root cause below it.
- We say the master node failed which sounds very bad but, well, you
know, that's just like, uh, our opinion. The master node is often
fine, it just rejected our checks for some reason.
- Reports of unstable clusters include these messages because they're
noisy and look important, but don't include the more informative ones
from the master because the master logs look quieter.
This commit reworks the logging in this area to avoid these problems:
- We use `DiscoveryNode#descriptionWithoutAttributes` throughout.
- We suppress the full stack traces unless `DEBUG` logging is on.
- The `LeaderChecker` now provides the message to be logged, rather than
putting all the details into an exception that wraps around the root
cause.
- The message describes the root cause rather than just saying that the
"master node failed"
- We distinguish timeouts from rejections and report the count of each.
- The message guides towards checking the master node logs too.
babf188 to
29ba8ad
Compare
Collaborator
|
Pinging @elastic/es-distributed (Team:Distributed) |
DaveCTurner
commented
Oct 11, 2021
| private class CheckScheduler implements Releasable { | ||
|
|
||
| private final AtomicBoolean isClosed = new AtomicBoolean(); | ||
| private final AtomicLong failureCountSinceLastSuccess = new AtomicLong(); |
Member
Author
There was a problem hiding this comment.
We don't actually need an AtomicLong here, there's only ever one request in flight so everything is properly synchronised already.
DaveCTurner
added a commit
that referenced
this pull request
Oct 15, 2021
Today if the `LeaderChecker` decides it's time to restart discovery then
we log a verbose and confusing message that looks something like this:
[instance-0000000006] master node [...] failed, restarting discovery
org.elasticsearch.ElasticsearchException: node [...] failed [3] consecutive checks
at org.elasticsearch.cluster.coordination.LeaderChecker$CheckScheduler$1.handleException(LeaderChecker.java:275) ~[elasticsearch-7.14.1.jar:7.14.1]
...
at java.lang.Thread.run(Thread.java:831) [?:?]
Caused by: org.elasticsearch.transport.RemoteTransportException: [...][internal:coordination/fault_detection/leader_check]
Caused by: org.elasticsearch.cluster.coordination.CoordinationStateRejectedException: rejecting leader check since [...] has been removed from the cluster
at org.elasticsearch.cluster.coordination.LeaderChecker.handleLeaderCheck(LeaderChecker.java:181) ~[elasticsearch-7.14.1.jar:7.14.1]
...
at java.lang.Thread.run(Thread.java:831) ~[?:?]
There's quite a few problems with this:
- We use `DiscoveryNode#toString` which is far too chatty.
- There's basically nothing useful in these stack traces.
- It's easy to miss the `RemoteTransportException` in the middle.
- It's also easy to miss the root cause below it.
- We say the master node failed which sounds very bad but, well, you
know, that's just like, uh, our opinion. The master node is often
fine, it just rejected our checks for some reason.
- Reports of unstable clusters include these messages because they're
noisy and look important, but don't include the more informative ones
from the master because the master logs look quieter.
This commit reworks the logging in this area to avoid these problems:
- We use `DiscoveryNode#descriptionWithoutAttributes` throughout.
- We suppress the full stack traces unless `DEBUG` logging is on.
- The `LeaderChecker` now provides the message to be logged, rather than
putting all the details into an exception that wraps around the root
cause.
- The message describes the root cause rather than just saying that the
"master node failed"
- We distinguish timeouts from rejections and report the count of each.
- The message guides towards checking the master node logs too.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
4 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Today if the
LeaderCheckerdecides it's time to restart discovery thenwe log a verbose and confusing message that looks something like this:
There's quite a few problems with this:
DiscoveryNode#toStringwhich is far too chatty.RemoteTransportExceptionin the middle.know, that's just like, uh, our opinion. The master node is often
fine, it just rejected our checks for some reason.
noisy and look important, but don't include the more informative ones
from the master because the master logs look quieter.
This commit reworks the logging in this area to avoid these problems:
DiscoveryNode#descriptionWithoutAttributesthroughout.DEBUGlogging is on.LeaderCheckernow provides the message to be logged, rather thanputting all the details into an exception that wraps around the root
cause.
"master node failed"