From 348b0d40a6cc7cda30c94ff44d65776cecdc018a Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Sun, 28 Jul 2019 21:06:05 -0500 Subject: [PATCH 1/7] embed: do not expose "zapLoggerBuilder" Signed-off-by: Gyuho Lee --- embed/config.go | 4 ++-- embed/config_logging.go | 10 +++++----- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/embed/config.go b/embed/config.go index d60493340..2087ae8af 100644 --- a/embed/config.go +++ b/embed/config.go @@ -307,8 +307,8 @@ type Config struct { // Debug is true, to enable debug level logging. Debug bool `json:"debug"` - // ZapLoggerBuilder is used to build the zap logger. - ZapLoggerBuilder func(*Config) error + // zapLoggerBuilder is used to build the zap logger. + zapLoggerBuilder func(*Config) error // logger logs server-side operations. The default is nil, // and "setupLogging" must be called before starting server. diff --git a/embed/config_logging.go b/embed/config_logging.go index 0478fb444..246444da1 100644 --- a/embed/config_logging.go +++ b/embed/config_logging.go @@ -162,8 +162,8 @@ func (cfg *Config) setupLogging() error { copied.Level = zap.NewAtomicLevelAt(zap.DebugLevel) grpc.EnableTracing = true } - if cfg.ZapLoggerBuilder == nil { - cfg.ZapLoggerBuilder = func(c *Config) error { + if cfg.zapLoggerBuilder == nil { + cfg.zapLoggerBuilder = func(c *Config) error { var err error c.logger, err = copied.Build() if err != nil { @@ -214,8 +214,8 @@ func (cfg *Config) setupLogging() error { syncer, lvl, ) - if cfg.ZapLoggerBuilder == nil { - cfg.ZapLoggerBuilder = func(c *Config) error { + if cfg.zapLoggerBuilder == nil { + cfg.zapLoggerBuilder = func(c *Config) error { c.logger = zap.New(cr, zap.AddCaller(), zap.ErrorOutput(syncer)) c.loggerMu.Lock() defer c.loggerMu.Unlock() @@ -231,7 +231,7 @@ func (cfg *Config) setupLogging() error { } } - err := cfg.ZapLoggerBuilder(cfg) + err := cfg.zapLoggerBuilder(cfg) if err != nil { return err } From e911f901a69030fff24facfa605a159196e065af Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Sun, 28 Jul 2019 21:36:55 -0500 Subject: [PATCH 2/7] pkg/logutil: add log level utilities Signed-off-by: Gyuho Lee --- pkg/logutil/log_level.go | 70 ++++++++++++++++++++++++++++++++++++++++ pkg/logutil/zap.go | 2 +- 2 files changed, 71 insertions(+), 1 deletion(-) create mode 100644 pkg/logutil/log_level.go diff --git a/pkg/logutil/log_level.go b/pkg/logutil/log_level.go new file mode 100644 index 000000000..d57e17394 --- /dev/null +++ b/pkg/logutil/log_level.go @@ -0,0 +1,70 @@ +// Copyright 2019 The etcd Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package logutil + +import ( + "fmt" + + "github.com/coreos/pkg/capnslog" + "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)) + } +} + +// ConvertToCapnslogLogLevel convert log level string to capnslog.LogLevel. +// TODO: deprecate this in 3.5 +func ConvertToCapnslogLogLevel(lvl string) capnslog.LogLevel { + switch lvl { + case "debug": + return capnslog.DEBUG + case "info": + return capnslog.INFO + case "warn": + return capnslog.WARNING + case "error": + return capnslog.ERROR + case "dpanic": + return capnslog.CRITICAL + case "panic": + return capnslog.CRITICAL + case "fatal": + return capnslog.CRITICAL + default: + panic(fmt.Sprintf("unknown level %q", lvl)) + } +} diff --git a/pkg/logutil/zap.go b/pkg/logutil/zap.go index 313d914c1..2f692233a 100644 --- a/pkg/logutil/zap.go +++ b/pkg/logutil/zap.go @@ -23,7 +23,7 @@ import ( // DefaultZapLoggerConfig defines default zap logger configuration. var DefaultZapLoggerConfig = zap.Config{ - Level: zap.NewAtomicLevelAt(zap.InfoLevel), + Level: zap.NewAtomicLevelAt(ConvertToZapLevel(DefaultLogLevel)), Development: false, Sampling: &zap.SamplingConfig{ From b9de4bddda1f927964c553733ebbb23b8945e166 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Sun, 28 Jul 2019 21:37:36 -0500 Subject: [PATCH 3/7] embed: add "LogLevel", deprecate "Debug" in v3.5 Make log level configurable, and deprecate "debug" flag in v3.5. And adds more warnings on flags that's being deprecated in v3.5. Signed-off-by: Gyuho Lee --- embed/config.go | 18 ++++++++++-------- embed/config_logging.go | 34 ++++++++++++++++++++++++++-------- 2 files changed, 36 insertions(+), 16 deletions(-) diff --git a/embed/config.go b/embed/config.go index 2087ae8af..0cc112001 100644 --- a/embed/config.go +++ b/embed/config.go @@ -30,6 +30,7 @@ import ( "go.etcd.io/etcd/etcdserver" "go.etcd.io/etcd/etcdserver/api/v3compactor" "go.etcd.io/etcd/pkg/flags" + "go.etcd.io/etcd/pkg/logutil" "go.etcd.io/etcd/pkg/netutil" "go.etcd.io/etcd/pkg/srv" "go.etcd.io/etcd/pkg/tlsutil" @@ -291,11 +292,8 @@ type Config struct { // Logger is logger options: "zap", "capnslog". // WARN: "capnslog" is being deprecated in v3.5. Logger string `json:"logger"` - - // DeprecatedLogOutput is to be deprecated in v3.5. - // Just here for safe migration in v3.4. - DeprecatedLogOutput []string `json:"log-output"` - + // LogLevel configures log level. Only supports debug, info, warn, error, panic, or fatal. Default 'info'. + LogLevel string `json:"log-level"` // LogOutputs is either: // - "default" as os.Stderr, // - "stderr" as os.Stderr, @@ -304,9 +302,6 @@ type Config struct { // It can be multiple when "Logger" is zap. LogOutputs []string `json:"log-outputs"` - // Debug is true, to enable debug level logging. - Debug bool `json:"debug"` - // zapLoggerBuilder is used to build the zap logger. zapLoggerBuilder func(*Config) error @@ -329,6 +324,12 @@ type Config struct { // TO BE DEPRECATED + // DeprecatedLogOutput is to be deprecated in v3.5. + // Just here for safe migration in v3.4. + DeprecatedLogOutput []string `json:"log-output"` + // Debug is true, to enable debug level logging. + // WARNING: to be deprecated in 3.5. Use "--log-level=debug" instead. + Debug bool `json:"debug"` // LogPkgLevels is being deprecated in v3.5. // Only valid if "logger" option is "capnslog". // WARN: DO NOT USE THIS! @@ -415,6 +416,7 @@ func NewConfig() *Config { DeprecatedLogOutput: []string{DefaultLogOutput}, LogOutputs: []string{DefaultLogOutput}, Debug: false, + LogLevel: logutil.DefaultLogLevel, LogPkgLevels: "", } cfg.InitialCluster = cfg.InitialClusterFromName(cfg.Name) diff --git a/embed/config_logging.go b/embed/config_logging.go index 246444da1..e617dfe82 100644 --- a/embed/config_logging.go +++ b/embed/config_logging.go @@ -69,11 +69,25 @@ func (cfg *Config) setupLogging() error { return fmt.Errorf("'--log-output=%q' and '--log-outputs=%q' are incompatible; only set --log-outputs", cfg.DeprecatedLogOutput, cfg.LogOutputs) } if !reflect.DeepEqual(cfg.DeprecatedLogOutput, []string{DefaultLogOutput}) { - fmt.Fprintf(os.Stderr, "Deprecated '--log-output' flag is set to %q\n", cfg.DeprecatedLogOutput) + fmt.Fprintf(os.Stderr, "[WARNING] Deprecated '--log-output' flag is set to %q\n", cfg.DeprecatedLogOutput) fmt.Fprintln(os.Stderr, "Please use '--log-outputs' flag") } } + // TODO: remove after deprecating log related flags in v3.5 + if cfg.Debug { + fmt.Fprintf(os.Stderr, "[WARNING] Deprecated '--debug' flag is set to %v (use '--log-level=debug' instead\n", cfg.Debug) + } + if cfg.Debug && cfg.LogLevel != "debug" { + fmt.Fprintf(os.Stderr, "[WARNING] Deprecated '--debug' flag is set to %v with inconsistent '--log-level=%s' flag\n", cfg.Debug, cfg.LogLevel) + } + if cfg.Logger == "capnslog" { + fmt.Fprintf(os.Stderr, "[WARNING] Deprecated '--logger=%s' flag is set; use '--logger=zap' flag instead\n", cfg.Logger) + } + if cfg.LogPkgLevels != "" { + fmt.Fprintf(os.Stderr, "[WARNING] Deprecated '--log-package-levels=%s' flag is set; use '--logger=zap' flag instead\n", cfg.LogPkgLevels) + } + switch cfg.Logger { case "capnslog": // TODO: deprecate this in v3.5 cfg.ClientTLSInfo.HandshakeFailure = logTLSHandshakeFailure @@ -85,7 +99,7 @@ func (cfg *Config) setupLogging() error { // enable info, warning, error grpclog.SetLoggerV2(grpclog.NewLoggerV2(os.Stderr, os.Stderr, os.Stderr)) } else { - capnslog.SetGlobalLogLevel(capnslog.INFO) + capnslog.SetGlobalLogLevel(logutil.ConvertToCapnslogLogLevel(cfg.LogLevel)) // only discard info grpclog.SetLoggerV2(grpclog.NewLoggerV2(ioutil.Discard, os.Stderr, os.Stderr)) } @@ -157,9 +171,11 @@ func (cfg *Config) setupLogging() error { if !isJournal { copied := logutil.AddOutputPaths(logutil.DefaultZapLoggerConfig, outputPaths, errOutputPaths) - - if cfg.Debug { - copied.Level = zap.NewAtomicLevelAt(zap.DebugLevel) + copied.Level = zap.NewAtomicLevelAt(logutil.ConvertToZapLevel(cfg.LogLevel)) + if cfg.Debug || cfg.LogLevel == "debug" { + // enable tracing even when "--debug --log-level info" + // in order to keep backward compatibility with <= v3.3 + // TODO: remove "Debug" check in v3.5 grpc.EnableTracing = true } if cfg.zapLoggerBuilder == nil { @@ -201,9 +217,11 @@ func (cfg *Config) setupLogging() error { return lerr } - lvl := zap.NewAtomicLevelAt(zap.InfoLevel) - if cfg.Debug { - lvl = zap.NewAtomicLevelAt(zap.DebugLevel) + lvl := zap.NewAtomicLevelAt(logutil.ConvertToZapLevel(cfg.LogLevel)) + if cfg.Debug || cfg.LogLevel == "debug" { + // enable tracing even when "--debug --log-level info" + // in order to keep backward compatibility with <= v3.3 + // TODO: remove "Debug" check in v3.5 grpc.EnableTracing = true } From a37f3441f5beb41dd4a3a14353cc3c382e92dff5 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Sun, 28 Jul 2019 21:45:16 -0500 Subject: [PATCH 4/7] etcdmain: add "--log-level" flag Signed-off-by: Gyuho Lee --- etcdmain/config.go | 10 ++++++---- etcdmain/help.go | 17 ++++++++++------- 2 files changed, 16 insertions(+), 11 deletions(-) diff --git a/etcdmain/config.go b/etcdmain/config.go index 12a22d4de..29947cbcb 100644 --- a/etcdmain/config.go +++ b/etcdmain/config.go @@ -28,6 +28,7 @@ import ( "go.etcd.io/etcd/embed" "go.etcd.io/etcd/pkg/flags" + "go.etcd.io/etcd/pkg/logutil" "go.etcd.io/etcd/pkg/types" "go.etcd.io/etcd/version" @@ -221,11 +222,12 @@ func newConfig() *config { fs.Var(flags.NewUniqueStringsValue("*"), "host-whitelist", "Comma-separated acceptable hostnames from HTTP client requests, if server is not secure (empty means allow all).") // logging - fs.StringVar(&cfg.ec.Logger, "logger", "capnslog", "Specify 'zap' for structured logging or 'capnslog'.") - fs.Var(flags.NewUniqueStringsValue(embed.DefaultLogOutput), "log-output", "DEPRECATED: use '--log-outputs'.") + fs.StringVar(&cfg.ec.Logger, "logger", "capnslog", "Specify 'zap' for structured logging or 'capnslog'. WARN: 'capnslog' is being deprecated in v3.5.") + fs.Var(flags.NewUniqueStringsValue(embed.DefaultLogOutput), "log-output", "[TO BE DEPRECATED IN v3.5] use '--log-outputs'.") fs.Var(flags.NewUniqueStringsValue(embed.DefaultLogOutput), "log-outputs", "Specify 'stdout' or 'stderr' to skip journald logging even when running under systemd, or list of comma separated output targets.") - fs.BoolVar(&cfg.ec.Debug, "debug", false, "Enable debug-level logging for etcd.") - fs.StringVar(&cfg.ec.LogPkgLevels, "log-package-levels", "", "(To be deprecated) Specify a particular log level for each etcd package (eg: 'etcdmain=CRITICAL,etcdserver=DEBUG').") + fs.BoolVar(&cfg.ec.Debug, "debug", false, "[TO BE DEPRECATED IN v3.5] Enable debug-level logging for etcd. Use '--log-level=debug' instead.") + fs.StringVar(&cfg.ec.LogLevel, "log-level", logutil.DefaultLogLevel, "Configures log level. Only supports debug, info, warn, error, panic, or fatal. Default 'info'.") + fs.StringVar(&cfg.ec.LogPkgLevels, "log-package-levels", "", "[TO BE DEPRECATED IN v3.5] Specify a particular log level for each etcd package (eg: 'etcdmain=CRITICAL,etcdserver=DEBUG').") // version fs.BoolVar(&cfg.printVersion, "version", false, "Print the version and exit.") diff --git a/etcdmain/help.go b/etcdmain/help.go index 4cf7b2328..28889c6a4 100644 --- a/etcdmain/help.go +++ b/etcdmain/help.go @@ -173,15 +173,11 @@ Profiling and Monitoring: Logging: --logger 'capnslog' - Specify 'zap' for structured logging or 'capnslog'. + Specify 'zap' for structured logging or 'capnslog'. [WARN] 'capnslog' will be deprecated in v3.5. --log-outputs 'default' Specify 'stdout' or 'stderr' to skip journald logging even when running under systemd, or list of comma separated output targets. - --debug 'false' - Enable debug-level logging for etcd. - -Logging (to be deprecated in v3.5): - --log-package-levels '' - Specify a particular log level for each etcd package (eg: 'etcdmain=CRITICAL,etcdserver=DEBUG'). + --log-level 'info' + Configures log level. Only supports debug, info, warn, error, panic, or fatal. v2 Proxy (to be deprecated in v4): --proxy 'off' @@ -214,5 +210,12 @@ Unsafe feature: Force to create a new one-member cluster. CAUTIOUS with unsafe flag! It may break the guarantees given by the consensus protocol! + +TO BE DEPRECATED: + + --debug 'false' + Enable debug-level logging for etcd. [WARN] Will be deprecated in v3.5. Use '--log-level=debug' instead. + --log-package-levels '' + Specify a particular log level for each etcd package (eg: 'etcdmain=CRITICAL,etcdserver=DEBUG'). ` ) From abba5421f5a93f4522323a5d94d1efdc54d256dc Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Sun, 28 Jul 2019 21:48:06 -0500 Subject: [PATCH 5/7] Documentation/op-guide: add "--log-level" flag Signed-off-by: Gyuho Lee --- Documentation/op-guide/configuration.md | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/Documentation/op-guide/configuration.md b/Documentation/op-guide/configuration.md index 9d9029633..3a682bcf9 100644 --- a/Documentation/op-guide/configuration.md +++ b/Documentation/op-guide/configuration.md @@ -342,7 +342,8 @@ The security flags help to [build a secure etcd cluster][security]. ### --logger -**Available from v3.4** +**Available from v3.4.** +**WARNING: `--logger=capnslog` to be deprecated in v3.5.** + Specify 'zap' for structured logging or 'capnslog'. + default: capnslog @@ -354,12 +355,27 @@ The security flags help to [build a secure etcd cluster][security]. + env variable: ETCD_LOG_OUTPUTS + 'default' use 'stderr' config for v3.4 during zap logger migraion +### --log-level + +**Available from v3.4.** + ++ Configures log level. Only supports debug, info, warn, error, panic, or fatal. ++ default: info ++ env variable: ETCD_LOG_LEVEL ++ 'default' use 'info'. + ### --debug + +**WARNING: to be deprecated in v3.5.** + + Drop the default log level to DEBUG for all subpackages. + default: false (INFO for all packages) + env variable: ETCD_DEBUG ### --log-package-levels + +**WARNING: to be deprecated in v3.5.** + + Set individual etcd subpackages to specific log levels. An example being `etcdserver=WARNING,security=DEBUG` + default: "" (INFO for all packages) + env variable: ETCD_LOG_PACKAGE_LEVELS From c6e340125501673d4e900dfc0efb2f4a1fc767d6 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Sun, 28 Jul 2019 22:18:23 -0500 Subject: [PATCH 6/7] etcdserver: make raft log configured by top level logger To make it consistent Signed-off-by: Gyuho Lee --- etcdserver/raft.go | 19 ++++++++++++------- pkg/logutil/zap_raft.go | 7 ++++++- 2 files changed, 18 insertions(+), 8 deletions(-) diff --git a/etcdserver/raft.go b/etcdserver/raft.go index 8095288ce..c0fe97905 100644 --- a/etcdserver/raft.go +++ b/etcdserver/raft.go @@ -58,13 +58,6 @@ var ( ) func init() { - lcfg := logutil.DefaultZapLoggerConfig - lg, err := logutil.NewRaftLogger(&lcfg) - if err != nil { - log.Fatalf("cannot create raft logger %v", err) - } - raft.SetLogger(lg) - expvar.Publish("raft.status", expvar.Func(func() interface{} { raftStatusMu.Lock() defer raftStatusMu.Unlock() @@ -124,6 +117,18 @@ type raftNodeConfig struct { } func newRaftNode(cfg raftNodeConfig) *raftNode { + var lg raft.Logger + if cfg.lg != nil { + lg = logutil.NewRaftLoggerZap(cfg.lg) + } else { + lcfg := logutil.DefaultZapLoggerConfig + var err error + lg, err = logutil.NewRaftLogger(&lcfg) + if err != nil { + log.Fatalf("cannot create raft logger %v", err) + } + } + raft.SetLogger(lg) r := &raftNode{ lg: cfg.lg, tickMu: new(sync.Mutex), diff --git a/pkg/logutil/zap_raft.go b/pkg/logutil/zap_raft.go index e92cba04c..f016b3054 100644 --- a/pkg/logutil/zap_raft.go +++ b/pkg/logutil/zap_raft.go @@ -23,7 +23,7 @@ import ( "go.uber.org/zap/zapcore" ) -// NewRaftLogger converts "*zap.Logger" to "raft.Logger". +// NewRaftLogger builds "raft.Logger" from "*zap.Config". func NewRaftLogger(lcfg *zap.Config) (raft.Logger, error) { if lcfg == nil { return nil, errors.New("nil zap.Config") @@ -35,6 +35,11 @@ func NewRaftLogger(lcfg *zap.Config) (raft.Logger, error) { return &zapRaftLogger{lg: lg, sugar: lg.Sugar()}, nil } +// NewRaftLoggerZap converts "*zap.Logger" to "raft.Logger". +func NewRaftLoggerZap(lg *zap.Logger) raft.Logger { + return &zapRaftLogger{lg: lg, sugar: lg.Sugar()} +} + // NewRaftLoggerFromZapCore creates "raft.Logger" from "zap.Core" // and "zapcore.WriteSyncer". func NewRaftLoggerFromZapCore(cr zapcore.Core, syncer zapcore.WriteSyncer) raft.Logger { From 4e43a082b219006f74d2a299658333991d561cd7 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Sun, 28 Jul 2019 23:05:32 -0500 Subject: [PATCH 7/7] raft: use mutex in "SetLogger" to avoid race conditions in tests Signed-off-by: Gyuho Lee --- raft/logger.go | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/raft/logger.go b/raft/logger.go index 426a77d34..6d8962965 100644 --- a/raft/logger.go +++ b/raft/logger.go @@ -19,6 +19,7 @@ import ( "io/ioutil" "log" "os" + "sync" ) type Logger interface { @@ -41,11 +42,16 @@ type Logger interface { Panicf(format string, v ...interface{}) } -func SetLogger(l Logger) { raftLogger = l } +func SetLogger(l Logger) { + raftLoggerMu.Lock() + raftLogger = l + raftLoggerMu.Unlock() +} var ( defaultLogger = &DefaultLogger{Logger: log.New(os.Stderr, "raft", log.LstdFlags)} discardLogger = &DefaultLogger{Logger: log.New(ioutil.Discard, "", 0)} + raftLoggerMu sync.Mutex raftLogger = Logger(defaultLogger) )