Merge pull request #10476 from gyuho/client-log

clientv3: clarify retry interceptor logging

clientv3/retry_interceptor.go

@@ -48,11 +48,21 @@ func (c *Client) unaryClientInterceptor(logger *zap.Logger, optFuncs ...retryOpt
 			if err := waitRetryBackoff(ctx, attempt, callOpts); err != nil {
 				return err
 			}
+			logger.Info(
+				"retrying of unary invoker",
+				zap.String("target", cc.Target()),
+				zap.Uint("attempt", attempt),
+			)
 			lastErr = invoker(ctx, method, req, reply, cc, grpcOpts...)
-			logger.Info("retry unary intercept", zap.Uint("attempt", attempt), zap.Error(lastErr))
 			if lastErr == nil {
 				return nil
 			}
+			logger.Warn(
+				"retrying of unary invoker failed",
+				zap.String("target", cc.Target()),
+				zap.Uint("attempt", attempt),
+				zap.Error(lastErr),
+			)
 			if isContextError(lastErr) {
 				if ctx.Err() != nil {
 					// its the context deadline or cancellation.
@@ -64,7 +74,11 @@ func (c *Client) unaryClientInterceptor(logger *zap.Logger, optFuncs ...retryOpt
 			if callOpts.retryAuth && rpctypes.Error(lastErr) == rpctypes.ErrInvalidAuthToken {
 				gterr := c.getToken(ctx)
 				if gterr != nil {
-					logger.Info("retry failed to fetch new auth token", zap.Error(gterr))
+					logger.Warn(
+						"retrying of unary invoker failed to fetch new auth token",
+						zap.String("target", cc.Target()),
+						zap.Error(gterr),
+					)
 					return lastErr // return the original error for simplicity
 				}
 				continue

tests/e2e/ctl_v3_auth_test.go

@@ -786,8 +786,19 @@ func authLeaseTestLeaseRevoke(cx ctlCtx) {
 	cx.user, cx.pass = "root", "root"
 	authSetupTestUser(cx)
 
-	if err := leaseTestRevoke(cx); err != nil {
-		cx.t.Fatalf("authLeaseTestLeaseRevoke: error (%v)", err)
+	// put with TTL 10 seconds and revoke
+	leaseID, err := ctlV3LeaseGrant(cx, 10)
+	if err != nil {
+		cx.t.Fatalf("ctlV3LeaseGrant error (%v)", err)
+	}
+	if err := ctlV3Put(cx, "key", "val", leaseID); err != nil {
+		cx.t.Fatalf("ctlV3Put error (%v)", err)
+	}
+	if err := ctlV3LeaseRevoke(cx, leaseID); err != nil {
+		cx.t.Fatalf("ctlV3LeaseRevoke error (%v)", err)
+	}
+	if err := ctlV3GetWithErr(cx, []string{"key"}, []string{"retrying of unary invoker failed"}); err != nil { // expect errors
+		cx.t.Fatalf("ctlV3GetWithErr error (%v)", err)
 	}
 }
 

tests/e2e/ctl_v3_kv_test.go

@@ -329,6 +329,16 @@ func ctlV3Get(cx ctlCtx, args []string, kvs ...kv) error {
 	return spawnWithExpects(cmdArgs, lines...)
 }
 
+// ctlV3GetWithErr runs "get" command expecting no output but error
+func ctlV3GetWithErr(cx ctlCtx, args []string, errs []string) error {
+	cmdArgs := append(cx.PrefixArgs(), "get")
+	cmdArgs = append(cmdArgs, args...)
+	if !cx.quorum {
+		cmdArgs = append(cmdArgs, "--consistency", "s")
+	}
+	return spawnWithExpects(cmdArgs, errs...)
+}
+
 func ctlV3Del(cx ctlCtx, args []string, num int) error {
 	cmdArgs := append(cx.PrefixArgs(), "del")
 	cmdArgs = append(cmdArgs, args...)