Merge pull request #11670 from tangcong/optimize-auth-store-log

*: optimize auth/etcdserver logs to facilitate troubleshooting data inconsistency

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
 	}
 
@@ -1065,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()

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

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