Merge pull request #12786 from ptabor/20210318-debug-env

client: Bring back ETCD_CLIENT_DEBUG variable interpretation.

CHANGELOG-3.5.md

@@ -66,9 +66,9 @@ See [code changes](https://github.com/etcd-io/etcd/compare/v3.4.0...v3.5.0) and
 - ClientV3 supports [grpc resolver API](https://github.com/etcd-io/etcd/blob/master/client/v3/naming/resolver/resolver.go).
   - Endpoints can be managed using [endpoints.Manager](https://github.com/etcd-io/etcd/blob/master/client/v3/naming/endpoints/endpoints.go)
   - Previously supported [GRPCResolver was decomissioned](https://github.com/etcd-io/etcd/pull/12675). Use [resolver](https://github.com/etcd-io/etcd/blob/master/client/v3/naming/resolver/resolver.go) instead.
-- Turned on [--pre-vote by default](https://github.com/etcd-io/etcd/pull/). Should prevent disrupting RAFT leader by an individual member. 
-
-### `etcdctl`
+- Turned on [--pre-vote by default](https://github.com/etcd-io/etcd/pull/12770). Should prevent disrupting RAFT leader by an individual member. 
+- [ETCD_CLIENT_DEBUG env](https://github.com/etcd-io/etcd/pull/12786): Now supports log levels (debug, info, warn, error, dpanic, panic, fatal). Only when set, overrides application-wide grpc logging settings.
+###
 
 - Make sure [save snapshot downloads checksum for integrity checks](https://github.com/etcd-io/etcd/pull/11896).
 
@@ -77,7 +77,7 @@ See [code changes](https://github.com/etcd-io/etcd/compare/v3.4.0...v3.5.0) and
 - Add [`TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256` and `TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256` to `etcd --cipher-suites`](https://github.com/etcd-io/etcd/pull/11864).
 - Changed [the format of WAL entries related to auth for not keeping password as a plain text](https://github.com/etcd-io/etcd/pull/11943).
 - Add third party [Security Audit Report](https://github.com/etcd-io/etcd/pull/12201).
-- A [log warning](https://github.com/etcd-io/etcd/pull/12242) is added when etcd use any existing directory that has a permission different than 700 on Linux and 777 on Windows.
+- A [log warning](https://github.com/etcd-io/etcd/pull/12242) is added when etcd uses any existing directory that has a permission different than 700 on Linux and 777 on Windows.
 
 ### Metrics, Monitoring
 

client/v3/client.go

@@ -27,7 +27,6 @@ import (
 	"go.etcd.io/etcd/client/v3/credentials"
 	"go.etcd.io/etcd/client/v3/internal/endpoint"
 	"go.etcd.io/etcd/client/v3/internal/resolver"
-	"go.etcd.io/etcd/pkg/v3/logutil"
 	"go.uber.org/zap"
 	"google.golang.org/grpc"
 	"google.golang.org/grpc/codes"
@@ -99,7 +98,9 @@ func NewFromURLs(urls []string) (*Client, error) {
 	return New(Config{Endpoints: urls})
 }
 
-// WithLogger sets a logger
+// WithLogger overrides the logger.
+// Does not changes grpcLogger, that can be explicitly configured
+// using grpc_zap.ReplaceGrpcLoggerV2(..) method.
 func (c *Client) WithLogger(lg *zap.Logger) *Client {
 	c.lgMu.Lock()
 	c.lg = lg
@@ -329,12 +330,12 @@ func newClient(cfg *Config) (*Client, error) {
 		lgMu:     new(sync.RWMutex),
 	}
 
-	lcfg := logutil.DefaultZapLoggerConfig
+	var err error
 	if cfg.LogConfig != nil {
-		lcfg = *cfg.LogConfig
+		client.lg, err = cfg.LogConfig.Build()
+	} else {
+		client.lg, err = createDefaultZapLogger()
 	}
-	var err error
-	client.lg, err = lcfg.Build()
 	if err != nil {
 		return nil, err
 	}

client/v3/logger.go

@@ -15,16 +15,61 @@
 package clientv3
 
 import (
-	"io/ioutil"
+	"log"
+	"os"
 
+	"go.etcd.io/etcd/pkg/v3/logutil"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
 	"google.golang.org/grpc/grpclog"
 )
 
 func init() {
-	SetLogger(grpclog.NewLoggerV2(ioutil.Discard, ioutil.Discard, ioutil.Discard))
+	// We override grpc logger only when the environment variable is set
+	// in order to not interfere by default with user's code or other libraries.
+	if os.Getenv("ETCD_CLIENT_DEBUG") != "" {
+		// We don't use grpc_zap.ReplaceGrpcLoggerV2(lg) to not push (wide) set
+		// of grpc-ecosystem/go-grpc-middleware dependencies on etcd-client users.
+		lg, err := logutil.NewGRPCLoggerV2(createDefaultZapLoggerConfig())
+		if err != nil {
+			panic(err)
+		}
+
+		grpclog.SetLoggerV2(lg)
+	}
 }
 
-// SetLogger sets client-side Logger.
+// SetLogger sets grpc logger.
+//
+// Deprecated: use grpclog.SetLoggerV2 directly or grpc_zap.ReplaceGrpcLoggerV2.
 func SetLogger(l grpclog.LoggerV2) {
 	grpclog.SetLoggerV2(l)
 }
+
+// etcdClientDebugLevel translates ETCD_CLIENT_DEBUG into zap log level.
+func etcdClientDebugLevel() zapcore.Level {
+	envLevel := os.Getenv("ETCD_CLIENT_DEBUG")
+	if envLevel == "" || envLevel == "true" {
+		return zapcore.InfoLevel
+	}
+	var l zapcore.Level
+	if err := l.Set(envLevel); err == nil {
+		log.Printf("Deprecated env ETCD_CLIENT_DEBUG value. Using default level: 'info'")
+		return zapcore.InfoLevel
+	}
+	return l
+}
+
+func createDefaultZapLoggerConfig() zap.Config {
+	lcfg := logutil.DefaultZapLoggerConfig
+	lcfg.Level = zap.NewAtomicLevelAt(etcdClientDebugLevel())
+	return lcfg
+}
+
+func createDefaultZapLogger() (*zap.Logger, error) {
+	c, err := createDefaultZapLoggerConfig().Build()
+	if err != nil {
+		return nil, err
+	}
+	return c.Named("etcd-client"), nil
+}

etcdctl/ctlv3/command/global.go

@@ -131,7 +131,7 @@ func clientConfigFromCmd(cmd *cobra.Command) *clientConfig {
 		ExitWithError(ExitError, err)
 	}
 	if debug {
-		clientv3.SetLogger(grpclog.NewLoggerV2WithVerbosity(os.Stderr, os.Stderr, os.Stderr, 4))
+		grpclog.SetLoggerV2(grpclog.NewLoggerV2WithVerbosity(os.Stderr, os.Stderr, os.Stderr, 4))
 		fs.VisitAll(func(f *pflag.Flag) {
 			fmt.Fprintf(os.Stderr, "%s=%v\n", flags.FlagToEnv("ETCDCTL", f.Name), f.Value)
 		})
@@ -140,7 +140,7 @@ func clientConfigFromCmd(cmd *cobra.Command) *clientConfig {
 		// too many routine connection disconnects to turn on by default.
 		//
 		// See https://github.com/etcd-io/etcd/pull/9623 for background
-		clientv3.SetLogger(grpclog.NewLoggerV2(ioutil.Discard, ioutil.Discard, os.Stderr))
+		grpclog.SetLoggerV2(grpclog.NewLoggerV2(ioutil.Discard, ioutil.Discard, os.Stderr))
 	}
 
 	cfg := &clientConfig{}

pkg/logutil/log_level.go

@@ -15,32 +15,16 @@
 package logutil
 
 import (
-	"fmt"
-
-	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
 )
 
 var DefaultLogLevel = "info"
 
 // ConvertToZapLevel converts log level string to zapcore.Level.
 func ConvertToZapLevel(lvl string) zapcore.Level {
-	switch lvl {
-	case "debug":
-		return zap.DebugLevel
-	case "info":
-		return zap.InfoLevel
-	case "warn":
-		return zap.WarnLevel
-	case "error":
-		return zap.ErrorLevel
-	case "dpanic":
-		return zap.DPanicLevel
-	case "panic":
-		return zap.PanicLevel
-	case "fatal":
-		return zap.FatalLevel
-	default:
-		panic(fmt.Sprintf("unknown level %q", lvl))
+	var level zapcore.Level
+	if err := level.Set(lvl); err != nil {
+		panic(err)
 	}
+	return level
 }

pkg/logutil/zap_grpc.go

@@ -36,7 +36,7 @@ func NewGRPCLoggerV2(lcfg zap.Config) (grpclog.LoggerV2, error) {
 // if debug level is not enabled in "*zap.Logger".
 func NewGRPCLoggerV2FromZapCore(cr zapcore.Core, syncer zapcore.WriteSyncer) grpclog.LoggerV2 {
 	// "AddCallerSkip" to annotate caller outside of "logutil"
-	lg := zap.New(cr, zap.AddCaller(), zap.AddCallerSkip(1), zap.ErrorOutput(syncer))
+	lg := zap.New(cr, zap.AddCaller(), zap.AddCallerSkip(1), zap.ErrorOutput(syncer)).Named("grpc")
 	return &zapGRPCLogger{lg: lg, sugar: lg.Sugar()}
 }
 

pkg/transport/sockopt_unix.go

@@ -1,3 +1,4 @@
+//go:build !windows
 // +build !windows
 
 package transport

pkg/transport/sockopt_windows.go

@@ -1,3 +1,4 @@
+//go:build windows
 // +build windows
 
 package transport

tests/integration/cluster.go

@@ -777,7 +777,11 @@ func NewClientV3(m *member) (*clientv3.Client, error) {
 	if m.DialOptions != nil {
 		cfg.DialOptions = append(cfg.DialOptions, m.DialOptions...)
 	}
-	return newClientV3(cfg)
+	c, err := newClientV3(cfg)
+	if err != nil {
+		return nil, err
+	}
+	return c.WithLogger(m.Logger.Named("client")), nil
 }
 
 // Clone returns a member with the same server configuration. The returned

tests/integration/v2store/store_tag_v2v3_test.go

@@ -18,21 +18,13 @@
 package v2store_test
 
 import (
-	"io/ioutil"
 	"testing"
 
-	"go.etcd.io/etcd/client/v3"
 	"go.etcd.io/etcd/server/v3/etcdserver/api/v2store"
 	"go.etcd.io/etcd/server/v3/etcdserver/api/v2v3"
 	"go.etcd.io/etcd/tests/v3/integration"
-
-	"google.golang.org/grpc/grpclog"
 )
 
-func init() {
-	clientv3.SetLogger(grpclog.NewLoggerV2(ioutil.Discard, ioutil.Discard, ioutil.Discard))
-}
-
 type v2v3TestStore struct {
 	v2store.Store
 	clus *integration.ClusterV3

tools/benchmark/cmd/util.go

@@ -123,7 +123,7 @@ func mustCreateConn() *clientv3.Client {
 		return mustCreateConn()
 	}
 
-	clientv3.SetLogger(grpclog.NewLoggerV2(os.Stderr, os.Stderr, os.Stderr))
+	grpclog.SetLoggerV2(grpclog.NewLoggerV2(os.Stderr, os.Stderr, os.Stderr))
 
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "dial error: %v\n", err)