diff --git a/etcdserver/v3_server.go b/etcdserver/v3_server.go index 6487fd0e909..fdbce738c1f 100644 --- a/etcdserver/v3_server.go +++ b/etcdserver/v3_server.go @@ -710,6 +710,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.getLogger()) nextnr := newNotifier() s.readMu.Lock() @@ -782,16 +785,26 @@ func (s *EtcdServer) linearizableReadLoop() { if !done { continue } + trace.Step("read index received") - if ai := s.getAppliedIndex(); ai < rs.Index { + index := rs.Index + trace.AddField(traceutil.Field{Key: "readStateIndex", Value: index}) + + ai := s.getAppliedIndex() + trace.AddField(traceutil.Field{Key: "appliedIndex", Value: ai}) + + if ai < index { select { - case <-s.applyWait.Wait(rs.Index): + case <-s.applyWait.Wait(index): case <-s.stopping: return } } // unblock all l-reads requested at indices before rs.Index nr.notify(nil) + trace.Step("applied index is now lower than readState.Index") + + trace.LogAllStepsIfLong(traceThreshold) } } diff --git a/pkg/traceutil/trace.go b/pkg/traceutil/trace.go index 2d247dd9acc..a3c32553df8 100644 --- a/pkg/traceutil/trace.go +++ b/pkg/traceutil/trace.go @@ -138,6 +138,13 @@ func (t *Trace) LogIfLong(threshold time.Duration) { } } +// LogAllStepsIfLong dumps all logs if the duration is longer than threshold +func (t *Trace) LogAllStepsIfLong(threshold time.Duration) { + if time.Since(t.startTime) > threshold { + t.LogWithStepThreshold(0) + } +} + // LogWithStepThreshold only dumps step whose duration is longer than step threshold func (t *Trace) LogWithStepThreshold(threshold time.Duration) { msg, fs := t.logInfo(threshold)