From ebe256d61c0456e58fd8ce479d7a5947f908ad25 Mon Sep 17 00:00:00 2001 From: tangcong Date: Tue, 3 Mar 2020 17:26:04 +0800 Subject: [PATCH 1/3] auth: print warning log when error is ErrAuthOldRevision --- auth/store.go | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/auth/store.go b/auth/store.go index 5672a9440e1..80297458494 100644 --- a/auth/store.go +++ b/auth/store.go @@ -851,8 +851,13 @@ func (as *authStore) isOpPermitted(userName string, revision uint64, key, rangeE if revision == 0 { return ErrUserEmpty } - - if revision < as.Revision() { + rev := as.Revision() + if revision < rev { + as.lg.Warn("request auth revision is less than current node auth revision", + zap.Uint64("current node auth revision", rev), + zap.Uint64("request auth revision", revision), + zap.ByteString("request key", key), + zap.Error(ErrAuthOldRevision)) return ErrAuthOldRevision } From 0d084d3a08f9eeff66f06ba69bb8b972a485d4f0 Mon Sep 17 00:00:00 2001 From: tangcong Date: Tue, 3 Mar 2020 17:38:37 +0800 Subject: [PATCH 2/3] auth: cleanup saveConsistentIndex in NewAuthStore --- auth/store.go | 1 - 1 file changed, 1 deletion(-) diff --git a/auth/store.go b/auth/store.go index 80297458494..beb07c0874c 100644 --- a/auth/store.go +++ b/auth/store.go @@ -1070,7 +1070,6 @@ func NewAuthStore(lg *zap.Logger, be backend.Backend, tp TokenProvider, bcryptCo if as.Revision() == 0 { as.commitRevision(tx) - as.saveConsistentIndex(tx) } as.setupMetricsReporter() From 5a17367923ad599bb67f07dbf6e461892c243197 Mon Sep 17 00:00:00 2001 From: tangcong Date: Tue, 10 Mar 2020 10:56:33 +0800 Subject: [PATCH 3/3] etcdserver: print warn log when failed to apply request --- etcdserver/apply.go | 3 +++ etcdserver/util.go | 15 +++++++++++++++ 2 files changed, 18 insertions(+) diff --git a/etcdserver/apply.go b/etcdserver/apply.go index 25e50ebbb25..1838e331a9d 100644 --- a/etcdserver/apply.go +++ b/etcdserver/apply.go @@ -132,6 +132,9 @@ func (a *applierV3backend) Apply(r *pb.InternalRaftRequest) *applyResult { ar := &applyResult{} defer func(start time.Time) { warnOfExpensiveRequest(a.s.getLogger(), start, &pb.InternalRaftStringer{Request: r}, ar.resp, ar.err) + if ar.err != nil { + warnOfFailedRequest(a.s.getLogger(), start, &pb.InternalRaftStringer{Request: r}, ar.resp, ar.err) + } }(time.Now()) // call into a.s.applyV3.F instead of a.F so upper appliers can check individual calls diff --git a/etcdserver/util.go b/etcdserver/util.go index 609d1995994..883e14f0fb5 100644 --- a/etcdserver/util.go +++ b/etcdserver/util.go @@ -111,6 +111,21 @@ func warnOfExpensiveRequest(lg *zap.Logger, now time.Time, reqStringer fmt.Strin warnOfExpensiveGenericRequest(lg, now, reqStringer, "", resp, err) } +func warnOfFailedRequest(lg *zap.Logger, now time.Time, reqStringer fmt.Stringer, respMsg proto.Message, err error) { + var resp string + if !isNil(respMsg) { + resp = fmt.Sprintf("size:%d", proto.Size(respMsg)) + } + d := time.Since(now) + lg.Warn( + "failed to apply request", + zap.Duration("took", d), + zap.String("request", reqStringer.String()), + zap.String("response", resp), + zap.Error(err), + ) +} + func warnOfExpensiveReadOnlyTxnRequest(lg *zap.Logger, now time.Time, r *pb.TxnRequest, txnResponse *pb.TxnResponse, err error) { reqStringer := pb.NewLoggableTxnRequest(r) var resp string