Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

etcdserver: add more detailed traces on linearized reading #12335

Merged
merged 1 commit into from
Sep 27, 2020

Conversation

PierreZ
Copy link
Contributor

@PierreZ PierreZ commented Sep 25, 2020

This PR is related to #11884

Why

To improve debuggability of agreement among raft nodes before linearized reading, we added some tracing inside linearizableReadLoop.

This will allow us to know the timing of s.r.ReadIndex vs s.applyWait.Wait(rs.Index).

Results

The patch has been deployed on clusters running v3.4.9, here's some traces:

{
  "level": "info",
  "ts": "2020-09-22T12:54:01.021Z",
  "caller": "traceutil/trace.go:152",
  "msg": "trace[2138445431] linearizableReadLoop",
  "detail": "",
  "duration": "855.447896ms",
  "start": "2020-09-22T12:54:00.166Z",
  "end": "2020-09-22T12:54:01.021Z",
  "steps": [
    "trace[2138445431] read index received  (duration: 824.408µs)",
    "trace[2138445431] applied index is now lower than readState.Index  (duration: 854.622058ms)"
  ]
}

@@ -775,6 +778,7 @@ func (s *EtcdServer) linearizableReadLoop() {
if !done {
continue
}
trace.Step("read index received")
Copy link
Contributor

Choose a reason for hiding this comment

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

can we add following fields to improve observability?
trace.AddField(traceutil.Field{Key: "appliedIndex", Value: s.getAppliedIndex})
trace.AddField(traceutil.Field{Key: "readStateIndex", Value: rs.Index})

Copy link
Contributor

Choose a reason for hiding this comment

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

@PierreZ PierreZ force-pushed the dev/11884/tracing/read_entries branch from 0fe5424 to a9ad9a9 Compare September 25, 2020 15:12
@@ -715,6 +716,9 @@ func (s *EtcdServer) linearizableReadLoop() {
return
}

// as a single loop is can unlock multiple reads, it is not very useful
// to propagate the trace from Txn or Range.
trace := traceutil.New("linearizableReadLoop", s.lg)
Copy link
Contributor

Choose a reason for hiding this comment

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

lg should be s.getLogger().

Copy link
Contributor

Choose a reason for hiding this comment

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

ci still failed.

To improve debuggability of `agreement among raft nodes before
linearized reading`, we added some tracing inside
`linearizableReadLoop`.

This will allow us to know the timing of `s.r.ReadIndex` vs
`s.applyWait.Wait(rs.Index)`.
@PierreZ PierreZ force-pushed the dev/11884/tracing/read_entries branch from a9ad9a9 to 19129ef Compare September 26, 2020 12:37
@tangcong
Copy link
Contributor

lgtm. thanks @PierreZ

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

3 participants