Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

Raft and state store indexes as metrics #5841

Merged
merged 5 commits into from
Jun 19, 2019
Merged

Conversation

preetapan
Copy link
Contributor

This PR makes every server emit raft commit and apply indexes, and the state store's latest index as metrics

Copy link
Member

@schmichael schmichael left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Don't forget docs and changelog. I think it's worth a quick test that spins up a TestServer and reads the metrics if for no other reason than to ensure we don't accidently break it in the future.

nomad/server.go Outdated
select {
case <-time.After(period):
commitIndex := s.raft.LastIndex()
metrics.SetGauge([]string{"raft", "commitIndex"}, float32(commitIndex))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should this be logIndex instead of commitIndex? At least the comments in https://github.com/hashicorp/raft/blob/master/state.go#L66 suggest (because of "cache") that we're getting a possibly stale index from the raft max(log, snapshot). This may be fine, I'm still a little hazy on which ids from raft may move backwards.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks to me like logIndex and commitIndex are distinct, and probably both helpful. The only place the commit index is returned from the raft api looks like its in the Stats call, https://github.com/hashicorp/raft/blob/master/api.go#L943

@@ -109,6 +109,18 @@ when retrieving metrics using the above described signals.
<td>Raft transactions / `interval`</td>
<td>Counter</td>
</tr>
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@langmartin @schmichael Can i get a review on these docs before I merge?

Copy link
Contributor

@notnoop notnoop left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

lgtm - had few comments but they aren't big deal.

func (s *Server) EmitRaftStats(period time.Duration, stopCh <-chan struct{}) {
for {
select {
case <-time.After(period):
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

very nit-picky - timer.Ticker is slightly nicer for using in loops, to reuse channels and timer mechanisms.

metrics.SetGauge([]string{"raft", "appliedIndex"}, float32(appliedIndex))
stateStoreSnapshotIndex, err := s.State().LatestIndex()
if err != nil {
s.logger.Warn("Unable to read snapshot index from statestore, metric will not be emitted", "error", err)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Curious - what conditions would result into an error getting the latest index? Also, is it meant to be recoverable? I'd be concerned about spurious logging if it happens somewhat frequently.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This should be rare and indicates state store corruption (either the index table is missing or contains invalid data). A lot of Nomad operations would be broken if it gets to that state so its a good thing to be warning about here.

</tr>
<tr>
<td>`nomad.raft.appliedIndex`</td>
<td>Index of the last applied log</td>
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

~ Is it worth adding some context and/or the caveat in https://godoc.org/github.com/hashicorp/raft#Raft.AppliedIndex :

This is generally lagging behind the last index, especially for indexes that are persisted but have not yet been considered committed by the leader. NOTE - this reflects the last index that was sent to the application's FSM over the apply channel but DOES NOT mean that the application's FSM has yet consumed it and applied it to its internal state. Thus, the application's state may lag behind this index.

nomad/server.go Outdated
@@ -410,6 +411,9 @@ func NewServer(config *Config, consulCatalog consul.CatalogAPI) (*Server, error)
// Emit metrics
go s.heartbeatStats()

// Emit raft and state store metrics
go s.EmitRaftStats(time.Second, s.shutdownCh)
Copy link
Contributor

@notnoop notnoop Jun 18, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I see how this matches other stats period, but I suspect that this is too frequent. Statsd agent commonly only flush data every few seconds seconds (e.g. 10 seconds for datadog [1] and statsite [2]), and with gauges, all values in the flush interval are dropped except for the last one [3].

Nothing to change now but raising awareness of potentially wasteful operations here and we can investigate/act later.

[1] https://docs.datadoghq.com/developers/dogstatsd/#how-it-works
[2] http://statsite.github.io/statsite/
[3] https://github.com/statsd/statsd/blob/master/docs/metric_types.md#gauges

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would it be more reasonable to use 10seconds here? The one potentially expensive call is state.LatestIndex which scans multiple memdb tables to find the max index. I'd rather fix this now to be more conservative about emitting stats.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, I'd go with 10s or 5s, and then we can reexamine other stats periods.

@@ -109,6 +109,18 @@ when retrieving metrics using the above described signals.
<td>Raft transactions / `interval`</td>
<td>Counter</td>
</tr>
<tr>
<td>`nomad.raft.lastIndex`</td>
<td>Index of the last log</td>
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

it's the index of the last log or snapshot, I assume there are cases where the snapshot can lead the logs. Since snapshot is just a view of the logs, this may not be a meaningful distinction

@preetapan preetapan merged commit c135f03 into master Jun 19, 2019
@notnoop notnoop deleted the f-raft-snapshot-metrics branch June 22, 2019 06:11
@github-actions
Copy link

github-actions bot commented Feb 8, 2023

I'm going to lock this pull request because it has been closed for 120 days ⏳. This helps our maintainers find and focus on the active contributions.
If you have found a problem that seems related to this change, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Feb 8, 2023
# for free to subscribe to this conversation on GitHub. Already have an account? #.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants