Skip to content

Commit bc8d3f6

Browse files
committed
Clientv3 (retry) logs should use the configured logger.
clientv3 logs (especially tests) were poluted with unattributed to testing.T log lines: ``` {"level":"warn","ts":"2021-04-29T12:42:11.055+0200","logger":"etcd-client","caller":"v3/retry_interceptor.go:64","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc0000fafc0/#initially=[unix://localhost:m10]","attempt":0,"error":"rpc error: code = ResourceExhausted desc = etcdserver: mvcc: database space exceeded"} ``` The reasons were 2 fold: - Interceptors were copying logger before "WithLogger" could modify it. - We were not propagating the loggers in a few testing contexts.
1 parent ed4a87d commit bc8d3f6

File tree

5 files changed

+14
-11
lines changed

5 files changed

+14
-11
lines changed

Diff for: client/v3/client.go

+2-2
Original file line numberDiff line numberDiff line change
@@ -215,8 +215,8 @@ func (c *Client) dialSetupOpts(creds grpccredentials.TransportCredentials, dopts
215215
opts = append(opts,
216216
// Disable stream retry by default since go-grpc-middleware/retry does not support client streams.
217217
// Streams that are safe to retry are enabled individually.
218-
grpc.WithStreamInterceptor(c.streamClientInterceptor(c.lg, withMax(0), rrBackoff)),
219-
grpc.WithUnaryInterceptor(c.unaryClientInterceptor(c.lg, withMax(defaultUnaryMaxRetries), rrBackoff)),
218+
grpc.WithStreamInterceptor(c.streamClientInterceptor(withMax(0), rrBackoff)),
219+
grpc.WithUnaryInterceptor(c.unaryClientInterceptor(withMax(defaultUnaryMaxRetries), rrBackoff)),
220220
)
221221

222222
return opts, nil

Diff for: client/v3/retry_interceptor.go

+7-7
Original file line numberDiff line numberDiff line change
@@ -35,7 +35,7 @@ import (
3535
//
3636
// The default configuration of the interceptor is to not retry *at all*. This behaviour can be
3737
// changed through options (e.g. WithMax) on creation of the interceptor or on call (through grpc.CallOptions).
38-
func (c *Client) unaryClientInterceptor(logger *zap.Logger, optFuncs ...retryOption) grpc.UnaryClientInterceptor {
38+
func (c *Client) unaryClientInterceptor(optFuncs ...retryOption) grpc.UnaryClientInterceptor {
3939
intOpts := reuseOrNewWithCallOptions(defaultOptions, optFuncs)
4040
return func(ctx context.Context, method string, req, reply interface{}, cc *grpc.ClientConn, invoker grpc.UnaryInvoker, opts ...grpc.CallOption) error {
4141
ctx = withVersion(ctx)
@@ -50,7 +50,7 @@ func (c *Client) unaryClientInterceptor(logger *zap.Logger, optFuncs ...retryOpt
5050
if err := waitRetryBackoff(ctx, attempt, callOpts); err != nil {
5151
return err
5252
}
53-
logger.Debug(
53+
c.GetLogger().Debug(
5454
"retrying of unary invoker",
5555
zap.String("target", cc.Target()),
5656
zap.Uint("attempt", attempt),
@@ -59,7 +59,7 @@ func (c *Client) unaryClientInterceptor(logger *zap.Logger, optFuncs ...retryOpt
5959
if lastErr == nil {
6060
return nil
6161
}
62-
logger.Warn(
62+
c.GetLogger().Warn(
6363
"retrying of unary invoker failed",
6464
zap.String("target", cc.Target()),
6565
zap.Uint("attempt", attempt),
@@ -82,7 +82,7 @@ func (c *Client) unaryClientInterceptor(logger *zap.Logger, optFuncs ...retryOpt
8282

8383
gterr := c.getToken(ctx)
8484
if gterr != nil {
85-
logger.Warn(
85+
c.GetLogger().Warn(
8686
"retrying of unary invoker failed to fetch new auth token",
8787
zap.String("target", cc.Target()),
8888
zap.Error(gterr),
@@ -107,7 +107,7 @@ func (c *Client) unaryClientInterceptor(logger *zap.Logger, optFuncs ...retryOpt
107107
// Retry logic is available *only for ServerStreams*, i.e. 1:n streams, as the internal logic needs
108108
// to buffer the messages sent by the client. If retry is enabled on any other streams (ClientStreams,
109109
// BidiStreams), the retry interceptor will fail the call.
110-
func (c *Client) streamClientInterceptor(logger *zap.Logger, optFuncs ...retryOption) grpc.StreamClientInterceptor {
110+
func (c *Client) streamClientInterceptor(optFuncs ...retryOption) grpc.StreamClientInterceptor {
111111
intOpts := reuseOrNewWithCallOptions(defaultOptions, optFuncs)
112112
return func(ctx context.Context, desc *grpc.StreamDesc, cc *grpc.ClientConn, method string, streamer grpc.Streamer, opts ...grpc.CallOption) (grpc.ClientStream, error) {
113113
ctx = withVersion(ctx)
@@ -117,7 +117,7 @@ func (c *Client) streamClientInterceptor(logger *zap.Logger, optFuncs ...retryOp
117117
// equal to c.Username != "" && c.Password != ""
118118
err := c.getToken(ctx)
119119
if err != nil && rpctypes.Error(err) != rpctypes.ErrAuthNotEnabled {
120-
logger.Error("clientv3/retry_interceptor: getToken failed", zap.Error(err))
120+
c.GetLogger().Error("clientv3/retry_interceptor: getToken failed", zap.Error(err))
121121
return nil, err
122122
}
123123
}
@@ -132,7 +132,7 @@ func (c *Client) streamClientInterceptor(logger *zap.Logger, optFuncs ...retryOp
132132
}
133133
newStreamer, err := streamer(ctx, desc, cc, method, grpcOpts...)
134134
if err != nil {
135-
logger.Error("streamer failed to create ClientStream", zap.Error(err))
135+
c.GetLogger().Error("streamer failed to create ClientStream", zap.Error(err))
136136
return nil, err // TODO(mwitkow): Maybe dial and transport errors should be retriable?
137137
}
138138
retryingStreamer := &serverStreamingRetryingStream{

Diff for: client/v3/snapshot/v3_snapshot.go

+2
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,8 @@ func Save(ctx context.Context, lg *zap.Logger, cfg clientv3.Config, dbPath strin
5656
}
5757
defer cli.Close()
5858

59+
cli = cli.WithLogger(lg.Named("client"))
60+
5961
partpath := dbPath + ".part"
6062
defer os.RemoveAll(partpath)
6163

Diff for: etcdctl/ctlv3/command/ep_command.go

+1
Original file line numberDiff line numberDiff line change
@@ -120,6 +120,7 @@ func epHealthCommandFunc(cmd *cobra.Command, args []string) {
120120
hch <- epHealth{Ep: ep, Health: false, Error: err.Error()}
121121
return
122122
}
123+
cli = cli.WithLogger(lg.Named("client"))
123124
st := time.Now()
124125
// get a random key. As long as we can get the response without an error, the
125126
// endpoint is health.

Diff for: server/etcdmain/grpc_proxy.go

+2-2
Original file line numberDiff line numberDiff line change
@@ -288,7 +288,7 @@ func mustNewClient(lg *zap.Logger) *clientv3.Client {
288288
fmt.Fprintln(os.Stderr, err)
289289
os.Exit(1)
290290
}
291-
return client
291+
return client.WithLogger(lg.Named("client"))
292292
}
293293

294294
func mustNewProxyClient(lg *zap.Logger, tls *transport.TLSInfo) *clientv3.Client {
@@ -304,7 +304,7 @@ func mustNewProxyClient(lg *zap.Logger, tls *transport.TLSInfo) *clientv3.Client
304304
os.Exit(1)
305305
}
306306
lg.Info("create proxy client", zap.String("grpcProxyAdvertiseClientURL", grpcProxyAdvertiseClientURL))
307-
return client
307+
return client.WithLogger(lg.Named("client"))
308308
}
309309

310310
func newProxyClientCfg(lg *zap.Logger, eps []string, tls *transport.TLSInfo) (*clientv3.Config, error) {

0 commit comments

Comments
 (0)