From 00c670932c4dbc76fa93fd3148af6bcdabf09854 Mon Sep 17 00:00:00 2001 From: nolouch Date: Wed, 10 Jul 2019 11:39:59 +0800 Subject: [PATCH] *:Start swithing to the zap logger (#1422) Signed-off-by: nolouch --- .gitignore | 2 + Gopkg.lock | 15 ++++-- Gopkg.toml | 8 +++ cmd/pd-server/main.go | 43 +++++++++++----- pkg/logutil/log.go | 5 +- pkg/logutil/log_test.go | 8 ++- server/api/server_test.go | 9 ++++ server/config.go | 33 ++++++++++-- server/server.go | 48 +++++++++-------- server/testutil.go | 13 ++++- server/util.go | 23 ++++++--- vendor/go.uber.org/zap/buffer/buffer.go | 9 ++++ vendor/go.uber.org/zap/config.go | 6 +-- vendor/go.uber.org/zap/doc.go | 2 +- vendor/go.uber.org/zap/global.go | 1 - vendor/go.uber.org/zap/http_handler.go | 4 +- vendor/go.uber.org/zap/writer.go | 51 ++++++++++--------- vendor/go.uber.org/zap/zapcore/field.go | 13 ++++- .../go.uber.org/zap/zapcore/json_encoder.go | 33 ++++++++++-- .../go.uber.org/zap/zapcore/memory_encoder.go | 4 +- 20 files changed, 240 insertions(+), 90 deletions(-) diff --git a/.gitignore b/.gitignore index 4c2ce9d9eba9..81e2de79eb92 100644 --- a/.gitignore +++ b/.gitignore @@ -7,3 +7,5 @@ default.pd .DS_Store tags /.retools/ +vendor +default* diff --git a/Gopkg.lock b/Gopkg.lock index e2379a0b2acf..a28a64dce7d4 100644 --- a/Gopkg.lock +++ b/Gopkg.lock @@ -325,6 +325,14 @@ pruneopts = "NUT" revision = "eec48234540b323cdfc3e92c4341d667fa245178" +[[projects]] + branch = "master" + digest = "1:1c69e1f3a2fd78cfd7fb489411cb620c110f7aded247db5c9ca00a073c2971f7" + name = "github.com/pingcap/log" + packages = ["."] + pruneopts = "NUT" + revision = "bd41d9273596826ed2cc8c70b3e8d307f459eca6" + [[projects]] digest = "1:5cf3f025cbee5951a4ee961de067c8a89fc95a5adabead774f82822efabab121" name = "github.com/pkg/errors" @@ -467,7 +475,7 @@ version = "v1.1.0" [[projects]] - digest = "1:25531f2a1f9e75b832a945c670bf84f8caf5bd0fe8d8ad5bab5f13e162680922" + digest = "1:4af5a022f8c5c97734c3c6fad58fdce078e2322ddc98d3102b225a729f03916e" name = "go.uber.org/zap" packages = [ ".", @@ -478,8 +486,8 @@ "zapcore", ] pruneopts = "NUT" - revision = "eeedf312bc6c57391d84767a4cd413f02a917974" - version = "v1.8.0" + revision = "27376062155ad36be76b0f12cf1572a221d3a48c" + version = "v1.10.0" [[projects]] branch = "master" @@ -643,6 +651,7 @@ "github.com/pingcap/kvproto/pkg/eraftpb", "github.com/pingcap/kvproto/pkg/metapb", "github.com/pingcap/kvproto/pkg/pdpb", + "github.com/pingcap/log", "github.com/pkg/errors", "github.com/prometheus/client_golang/prometheus", "github.com/prometheus/client_golang/prometheus/push", diff --git a/Gopkg.toml b/Gopkg.toml index 9c97b30373c6..241c25ba72f8 100644 --- a/Gopkg.toml +++ b/Gopkg.toml @@ -43,3 +43,11 @@ [[override]] name = "github.com/BurntSushi/toml" revision = "3012a1dbe2e4bd1391d42b32f0577cb7bbc7f005" + +[[constraint]] + branch = "master" + name = "github.com/pingcap/log" + +[[constraint]] + name = "go.uber.org/zap" + version = "1.9.1" diff --git a/cmd/pd-server/main.go b/cmd/pd-server/main.go index 39c457415ce8..8cf1306930cf 100644 --- a/cmd/pd-server/main.go +++ b/cmd/pd-server/main.go @@ -16,18 +16,18 @@ package main import ( "context" "flag" - "fmt" "os" "os/signal" "syscall" - "github.com/grpc-ecosystem/go-grpc-prometheus" + grpc_prometheus "github.com/grpc-ecosystem/go-grpc-prometheus" + log "github.com/pingcap/log" "github.com/pingcap/pd/pkg/logutil" "github.com/pingcap/pd/pkg/metricutil" "github.com/pingcap/pd/server" "github.com/pingcap/pd/server/api" "github.com/pkg/errors" - log "github.com/sirupsen/logrus" + "go.uber.org/zap" // Register schedulers. _ "github.com/pingcap/pd/server/schedulers" @@ -41,7 +41,7 @@ func main() { if cfg.Version { server.PrintPDInfo() - os.Exit(0) + exit(0) } defer logutil.LogPanic() @@ -49,14 +49,24 @@ func main() { switch errors.Cause(err) { case nil: case flag.ErrHelp: - os.Exit(0) + exit(0) default: - log.Fatalf("parse cmd flags error: %s\n", fmt.Sprintf("%+v", err)) + log.Fatal("parse cmd flags error", zap.Error(err)) } + // New zap logger + err = cfg.SetupLogger() + if err == nil { + log.ReplaceGlobals(cfg.GetZapLogger(), cfg.GetZapLogProperties()) + } else { + log.Fatal("initialize logger error", zap.Error(err)) + } + // Flushing any buffered log entries + defer log.Sync() + // The old logger err = logutil.InitLogger(&cfg.Log) if err != nil { - log.Fatalf("initialize logger error: %s\n", fmt.Sprintf("%+v", err)) + log.Fatal("initialize logger error", zap.Error(err)) } server.LogPDInfo() @@ -72,15 +82,15 @@ func main() { err = server.PrepareJoinCluster(cfg) if err != nil { - log.Fatal("join error ", fmt.Sprintf("%+v", err)) + log.Fatal("join meet error", zap.Error(err)) } svr, err := server.CreateServer(cfg, api.NewHandler) if err != nil { - log.Fatalf("create server failed: %v", fmt.Sprintf("%+v", err)) + log.Fatal("create server failed", zap.Error(err)) } if err = server.InitHTTPClient(svr); err != nil { - log.Fatalf("initial http client for api handler failed: %v", fmt.Sprintf("%+v", err)) + log.Fatal("initial http client for api handler failed", zap.Error(err)) } sc := make(chan os.Signal, 1) @@ -98,17 +108,22 @@ func main() { }() if err := svr.Run(ctx); err != nil { - log.Fatalf("run server failed: %v", fmt.Sprintf("%+v", err)) + log.Fatal("run server failed", zap.Error(err)) } <-ctx.Done() - log.Infof("Got signal [%d] to exit.", sig) + log.Info("Got signal to exit", zap.String("signal", sig.String())) svr.Close() switch sig { case syscall.SIGTERM: - os.Exit(0) + exit(0) default: - os.Exit(1) + exit(1) } } + +func exit(code int) { + log.Sync() + os.Exit(code) +} diff --git a/pkg/logutil/log.go b/pkg/logutil/log.go index 5ae1bf9264c2..9ad5a439056a 100644 --- a/pkg/logutil/log.go +++ b/pkg/logutil/log.go @@ -25,6 +25,7 @@ import ( "github.com/coreos/etcd/raft" "github.com/coreos/pkg/capnslog" + zaplog "github.com/pingcap/log" "github.com/pkg/errors" log "github.com/sirupsen/logrus" "google.golang.org/grpc/grpclog" @@ -196,7 +197,7 @@ func stringToLogFormatter(format string, disableTimestamp bool) log.Formatter { } // InitFileLog initializes file based logging options. -func InitFileLog(cfg *FileLogConfig) error { +func InitFileLog(cfg *zaplog.FileLogConfig) error { if st, err := os.Stat(cfg.Filename); err == nil { if st.IsDir() { return errors.New("can't use directory as log file name") @@ -238,7 +239,7 @@ func (lg *wrapLogrus) V(l int) bool { var once sync.Once // InitLogger initializes PD's logger. -func InitLogger(cfg *LogConfig) error { +func InitLogger(cfg *zaplog.Config) error { var err error once.Do(func() { diff --git a/pkg/logutil/log_test.go b/pkg/logutil/log_test.go index 07b8815997ef..4a62c583b3ac 100644 --- a/pkg/logutil/log_test.go +++ b/pkg/logutil/log_test.go @@ -20,6 +20,7 @@ import ( "github.com/coreos/pkg/capnslog" . "github.com/pingcap/check" + zaplog "github.com/pingcap/log" log "github.com/sirupsen/logrus" ) @@ -53,7 +54,7 @@ func (s *testLogSuite) TestStringToLogLevel(c *C) { // TestLogging assure log format and log redirection works. func (s *testLogSuite) TestLogging(c *C) { - conf := &LogConfig{Level: "warn", File: FileLogConfig{}} + conf := &zaplog.Config{Level: "warn", File: zaplog.FileLogConfig{}} c.Assert(InitLogger(conf), IsNil) log.SetOutput(s.buf) @@ -76,3 +77,8 @@ func (s *testLogSuite) TestLogging(c *C) { c.Assert(entry, Matches, logPattern) c.Assert(strings.Contains(entry, "log_test.go"), IsTrue) } + +func (s *testLogSuite) TestFileLog(c *C) { + c.Assert(InitFileLog(&zaplog.FileLogConfig{Filename: "/tmp"}), NotNil) + c.Assert(InitFileLog(&zaplog.FileLogConfig{Filename: "/tmp/test_file_log", MaxSize: 0}), IsNil) +} diff --git a/server/api/server_test.go b/server/api/server_test.go index 68d9b6131d30..542342a8f02d 100644 --- a/server/api/server_test.go +++ b/server/api/server_test.go @@ -18,12 +18,14 @@ import ( "net/http" "os" "strings" + "sync" "testing" "time" . "github.com/pingcap/check" "github.com/pingcap/kvproto/pkg/metapb" "github.com/pingcap/kvproto/pkg/pdpb" + log "github.com/pingcap/log" "github.com/pingcap/pd/pkg/testutil" "github.com/pingcap/pd/server" "google.golang.org/grpc" @@ -73,6 +75,8 @@ func mustNewServer(c *C) (*server.Server, cleanUpFunc) { return svrs[0], cleanup } +var zapLogOnce sync.Once + func mustNewCluster(c *C, num int) ([]*server.Config, []*server.Server, cleanUpFunc) { svrs := make([]*server.Server, 0, num) cfgs := server.NewTestMultiConfig(num) @@ -80,6 +84,11 @@ func mustNewCluster(c *C, num int) ([]*server.Config, []*server.Server, cleanUpF ch := make(chan *server.Server, num) for _, cfg := range cfgs { go func(cfg *server.Config) { + err := cfg.SetupLogger() + c.Assert(err, IsNil) + zapLogOnce.Do(func() { + log.ReplaceGlobals(cfg.GetZapLogger(), cfg.GetZapLogProperties()) + }) s, err := server.CreateServer(cfg, NewHandler) c.Assert(err, IsNil) err = s.Run(context.TODO()) diff --git a/server/config.go b/server/config.go index a295e7f92fbc..95c9259b67de 100644 --- a/server/config.go +++ b/server/config.go @@ -27,11 +27,12 @@ import ( "github.com/coreos/etcd/embed" "github.com/coreos/etcd/pkg/transport" "github.com/coreos/go-semver/semver" - "github.com/pingcap/pd/pkg/logutil" + "github.com/pingcap/log" "github.com/pingcap/pd/pkg/metricutil" "github.com/pingcap/pd/pkg/typeutil" "github.com/pingcap/pd/server/namespace" "github.com/pkg/errors" + "go.uber.org/zap" ) // Config is the pd server configuration. @@ -61,7 +62,7 @@ type Config struct { LeaderLease int64 `toml:"lease" json:"lease"` // Log related config. - Log logutil.LogConfig `toml:"log" json:"log"` + Log log.Config `toml:"log" json:"log"` // Backward compatibility. LogFileDeprecated string `toml:"log-file" json:"log-file"` @@ -123,6 +124,9 @@ type Config struct { heartbeatStreamBindInterval typeutil.Duration leaderPriorityCheckInterval typeutil.Duration + + logger *zap.Logger + logProps *log.ZapProperties } // NewConfig creates a new config. @@ -756,6 +760,27 @@ func ParseUrls(s string) ([]url.URL, error) { return urls, nil } +// SetupLogger setup the logger. +func (c *Config) SetupLogger() error { + lg, p, err := log.InitLogger(&c.Log) + if err != nil { + return err + } + c.logger = lg + c.logProps = p + return nil +} + +// GetZapLogger gets the created zap logger. +func (c *Config) GetZapLogger() *zap.Logger { + return c.logger +} + +// GetZapLogProperties gets properties of the zap logger. +func (c *Config) GetZapLogProperties() *log.ZapProperties { + return c.logProps +} + // generates a configuration for embedded etcd. func (c *Config) genEmbedEtcdConfig() (*embed.Config, error) { cfg := embed.NewConfig() @@ -780,7 +805,9 @@ func (c *Config) genEmbedEtcdConfig() (*embed.Config, error) { cfg.PeerTLSInfo.TrustedCAFile = c.Security.CAPath cfg.PeerTLSInfo.CertFile = c.Security.CertPath cfg.PeerTLSInfo.KeyFile = c.Security.KeyPath - + // TODO: update etcd + // cfg.ZapLoggerBuilder = embed.NewZapCoreLoggerBuilder(c.logger, c.logger.Core(), c.logSyncer) + // cfg.Logger = "zap" var err error cfg.LPUrls, err = ParseUrls(c.PeerUrls) diff --git a/server/server.go b/server/server.go index da74b250e6f7..a402679edb9b 100644 --- a/server/server.go +++ b/server/server.go @@ -31,12 +31,13 @@ import ( "github.com/coreos/go-semver/semver" "github.com/pingcap/kvproto/pkg/metapb" "github.com/pingcap/kvproto/pkg/pdpb" + log "github.com/pingcap/log" "github.com/pingcap/pd/pkg/etcdutil" "github.com/pingcap/pd/pkg/logutil" "github.com/pingcap/pd/server/core" "github.com/pingcap/pd/server/namespace" "github.com/pkg/errors" - log "github.com/sirupsen/logrus" + "go.uber.org/zap" "google.golang.org/grpc" ) @@ -97,11 +98,14 @@ type Server struct { lastSavedTime time.Time // For async region heartbeat. hbStreams *heartbeatStreams + // Zap logger + lg *zap.Logger + logProps *log.ZapProperties } // CreateServer creates the UNINITIALIZED pd server with given configuration. func CreateServer(cfg *Config, apiRegister func(*Server) http.Handler) (*Server, error) { - log.Infof("PD config - %v", cfg) + log.Info("PD Config", zap.Reflect("config", cfg)) rand.Seed(time.Now().UnixNano()) s := &Server{ @@ -124,11 +128,14 @@ func CreateServer(cfg *Config, apiRegister func(*Server) http.Handler) (*Server, s.etcdCfg = etcdCfg if EnableZap { // The etcd master version has removed embed.Config.SetupLogging. - // Now logger is set up automatically based on embed.Config.Logger, embed.Config.LogOutputs, embed.Config.Debug fields. - // Use zap logger in the test, otherwise will panic. Reference: https://github.com/coreos/etcd/blob/master/embed/config_logging.go#L45 + // Now logger is set up automatically based on embed.Config.Logger, + // Use zap logger in the test, otherwise will panic. + // Reference: https://github.com/coreos/etcd/blob/master/embed/config_logging.go#L45 s.etcdCfg.Logger = "zap" s.etcdCfg.LogOutputs = []string{"stdout"} } + s.lg = cfg.logger + s.logProps = cfg.logProps return s, nil } @@ -163,7 +170,7 @@ func (s *Server) startEtcd(ctx context.Context) error { } endpoints := []string{s.etcdCfg.ACUrls[0].String()} - log.Infof("create etcd v3 client with endpoints %v", endpoints) + log.Info("create etcd v3 client", zap.Strings("endpoints", endpoints)) client, err := clientv3.New(clientv3.Config{ Endpoints: endpoints, @@ -185,7 +192,7 @@ func (s *Server) startEtcd(ctx context.Context) error { if etcdServerID == m.ID { etcdPeerURLs := strings.Join(m.PeerURLs, ",") if s.cfg.AdvertisePeerUrls != etcdPeerURLs { - log.Infof("update advertise peer urls from %s to %s", s.cfg.AdvertisePeerUrls, etcdPeerURLs) + log.Info("update advertise peer urls", zap.String("from", s.cfg.AdvertisePeerUrls), zap.String("to", etcdPeerURLs)) s.cfg.AdvertisePeerUrls = etcdPeerURLs } } @@ -202,7 +209,7 @@ func (s *Server) startServer() error { if err = s.initClusterID(); err != nil { return err } - log.Infof("init cluster id %v", s.clusterID) + log.Info("init cluster id", zap.Uint64("cluster-id", s.clusterID)) // It may lose accuracy if use float64 to store uint64. So we store the // cluster id in label. metadataGauge.WithLabelValues(fmt.Sprintf("cluster%d", s.clusterID)).Set(0) @@ -277,7 +284,7 @@ var timeMonitorOnce sync.Once func (s *Server) Run(ctx context.Context) error { timeMonitorOnce.Do(func() { go StartMonitor(time.Now, func() { - log.Errorf("system time jumps backward") + log.Error("system time jumps backward") timeJumpBackCounter.Inc() }) }) @@ -334,7 +341,9 @@ func (s *Server) collectEtcdStateMetrics() { func (s *Server) bootstrapCluster(req *pdpb.BootstrapRequest) (*pdpb.BootstrapResponse, error) { clusterID := s.clusterID - log.Infof("try to bootstrap raft cluster %d with %v", clusterID, req) + log.Info("try to bootstrap raft cluster", + zap.Uint64("cluster-id", clusterID), + zap.String("request", fmt.Sprintf("%v", req))) if err := checkBootstrapRequest(clusterID, req); err != nil { return nil, err @@ -387,11 +396,11 @@ func (s *Server) bootstrapCluster(req *pdpb.BootstrapRequest) (*pdpb.BootstrapRe return nil, errors.WithStack(err) } if !resp.Succeeded { - log.Warnf("cluster %d already bootstrapped", clusterID) + log.Warn("cluster already bootstrapped", zap.Uint64("cluster-id", clusterID)) return nil, errors.Errorf("cluster %d already bootstrapped", clusterID) } - log.Infof("bootstrap cluster %d ok", clusterID) + log.Info("bootstrap cluster ok", zap.Uint64("cluster-id", clusterID)) if err := s.cluster.start(); err != nil { return nil, err @@ -491,7 +500,7 @@ func (s *Server) SetScheduleConfig(cfg ScheduleConfig) error { if err := s.scheduleOpt.persist(s.kv); err != nil { return err } - log.Infof("schedule config is updated: %+v, old: %+v", cfg, old) + log.Info("schedule config is updated", zap.Reflect("new", cfg), zap.Reflect("old", old)) return nil } @@ -509,11 +518,10 @@ func (s *Server) SetReplicationConfig(cfg ReplicationConfig) error { } old := s.scheduleOpt.rep.load() s.scheduleOpt.rep.store(&cfg) - s.scheduleOpt.persist(s.kv) if err := s.scheduleOpt.persist(s.kv); err != nil { return err } - log.Infof("replication config is updated: %+v, old: %+v", cfg, old) + log.Info("replication config is updated", zap.Reflect("new", cfg), zap.Reflect("old", old)) return nil } @@ -548,11 +556,11 @@ func (s *Server) SetNamespaceConfig(name string, cfg NamespaceConfig) { old := s.scheduleOpt.ns[name].load() n.store(&cfg) s.scheduleOpt.persist(s.kv) - log.Infof("namespace:%v config is updated: %+v, old: %+v", name, cfg, old) + log.Info("namespace config is updated", zap.String("name", name), zap.Reflect("new", cfg), zap.Reflect("old", old)) } else { s.scheduleOpt.ns[name] = newNamespaceOption(&cfg) s.scheduleOpt.persist(s.kv) - log.Infof("namespace:%v config is added: %+v", name, cfg) + log.Info("namespace config is added", zap.String("name", name), zap.Reflect("new", cfg)) } } @@ -562,7 +570,7 @@ func (s *Server) DeleteNamespaceConfig(name string) { cfg := n.load() delete(s.scheduleOpt.ns, name) s.scheduleOpt.persist(s.kv) - log.Infof("namespace:%v config is deleted: %+v", name, *cfg) + log.Info("namespace config is deleted", zap.String("name", name), zap.Reflect("config", *cfg)) } } @@ -573,7 +581,7 @@ func (s *Server) SetLabelProperty(typ, labelKey, labelValue string) error { if err != nil { return err } - log.Infof("label property config is updated: %+v", s.scheduleOpt.loadLabelPropertyConfig()) + log.Info("label property config is updated", zap.Reflect("config", s.scheduleOpt.loadLabelPropertyConfig())) return nil } @@ -584,7 +592,7 @@ func (s *Server) DeleteLabelProperty(typ, labelKey, labelValue string) error { if err != nil { return err } - log.Infof("label property config is updated: %+v", s.scheduleOpt.loadLabelPropertyConfig()) + log.Info("label property config is deleted", zap.Reflect("config", s.scheduleOpt.loadLabelPropertyConfig())) return nil } @@ -604,7 +612,7 @@ func (s *Server) SetClusterVersion(v string) error { if err != nil { return err } - log.Infof("cluster version is updated to %s", v) + log.Info("cluster version is updated", zap.String("new-version", v)) return nil } diff --git a/server/testutil.go b/server/testutil.go index 0596c58c4d3a..2ee46830fc75 100644 --- a/server/testutil.go +++ b/server/testutil.go @@ -19,9 +19,11 @@ import ( "io/ioutil" "os" "strings" + "sync" "time" "github.com/coreos/etcd/embed" + "github.com/pingcap/log" "github.com/pingcap/pd/pkg/tempurl" "github.com/pingcap/pd/pkg/typeutil" "github.com/pingcap/pd/server/schedule" @@ -56,6 +58,8 @@ func NewTestServer() (*Config, *Server, CleanupFunc, error) { return cfg, s, cleanup, nil } +var zapLogOnce sync.Once + // NewTestSingleConfig is only for test to create one pd. // Because PD client also needs this, so export here. func NewTestSingleConfig() *Config { @@ -76,8 +80,15 @@ func NewTestSingleConfig() *Config { cfg.InitialCluster = fmt.Sprintf("pd=%s", cfg.PeerUrls) cfg.disableStrictReconfigCheck = true cfg.TickInterval = typeutil.NewDuration(100 * time.Millisecond) - cfg.ElectionInterval = typeutil.NewDuration(3000 * time.Millisecond) + cfg.ElectionInterval = typeutil.NewDuration(3 * time.Second) cfg.leaderPriorityCheckInterval = typeutil.NewDuration(100 * time.Millisecond) + err := cfg.SetupLogger() + if err != nil { + log.Fatal("setup logger failed") + } + zapLogOnce.Do(func() { + log.ReplaceGlobals(cfg.GetZapLogger(), cfg.GetZapLogProperties()) + }) cfg.Adjust(nil) diff --git a/server/util.go b/server/util.go index 416cbb5cdcba..138efd5543b0 100644 --- a/server/util.go +++ b/server/util.go @@ -26,9 +26,10 @@ import ( "github.com/golang/protobuf/proto" "github.com/pingcap/kvproto/pkg/metapb" "github.com/pingcap/kvproto/pkg/pdpb" + log "github.com/pingcap/log" "github.com/pingcap/pd/pkg/etcdutil" "github.com/pkg/errors" - log "github.com/sirupsen/logrus" + "go.uber.org/zap" ) const ( @@ -55,11 +56,11 @@ var dialClient = &http.Client{ // LogPDInfo prints the PD version information. func LogPDInfo() { - log.Infof("Welcome to Placement Driver (PD).") - log.Infof("Release Version: %s", PDReleaseVersion) - log.Infof("Git Commit Hash: %s", PDGitHash) - log.Infof("Git Branch: %s", PDGitBranch) - log.Infof("UTC Build Time: %s", PDBuildTS) + log.Info("Welcome to Placement Driver (PD)") + log.Info("PD", zap.String("release-version", PDReleaseVersion)) + log.Info("PD", zap.String("git-hash", PDGitHash)) + log.Info("PD", zap.String("git-branch", PDGitBranch)) + log.Info("PD", zap.String("utc-build-time", PDBuildTS)) } // PrintPDInfo prints the PD version information without log info. @@ -78,7 +79,10 @@ func CheckPDVersion(opt *scheduleOption) { } clusterVersion := opt.loadClusterVersion() if pdVersion.LessThan(clusterVersion) { - log.Warnf("PD version %s less than cluster version: %s, please upgrade PD", pdVersion, clusterVersion) + log.Warn( + "PD version less than cluster version, please upgrade PD", + zap.String("PD-version", pdVersion.String()), + zap.String("cluster-version", clusterVersion.String())) } } @@ -213,7 +217,10 @@ func (t *slowLogTxn) Commit() (*clientv3.TxnResponse, error) { cost := time.Since(start) if cost > slowRequestTime { - log.Warnf("txn runs too slow, resp: %v, err: %v, cost: %s", resp, err, cost) + log.Warn("txn runs too slow", + zap.Error(err), + zap.Reflect("response", resp), + zap.Duration("cost", cost)) } label := "success" if err != nil { diff --git a/vendor/go.uber.org/zap/buffer/buffer.go b/vendor/go.uber.org/zap/buffer/buffer.go index d15f7fdb35be..7592e8c63f66 100644 --- a/vendor/go.uber.org/zap/buffer/buffer.go +++ b/vendor/go.uber.org/zap/buffer/buffer.go @@ -98,6 +98,15 @@ func (b *Buffer) Write(bs []byte) (int, error) { return len(bs), nil } +// TrimNewline trims any final "\n" byte from the end of the buffer. +func (b *Buffer) TrimNewline() { + if i := len(b.bs) - 1; i >= 0 { + if b.bs[i] == '\n' { + b.bs = b.bs[:i] + } + } +} + // Free returns the Buffer to its Pool. // // Callers must not retain references to the Buffer after calling Free. diff --git a/vendor/go.uber.org/zap/config.go b/vendor/go.uber.org/zap/config.go index dae130303e7d..6fe17d9e0f56 100644 --- a/vendor/go.uber.org/zap/config.go +++ b/vendor/go.uber.org/zap/config.go @@ -74,10 +74,10 @@ type Config struct { // EncoderConfig sets options for the chosen encoder. See // zapcore.EncoderConfig for details. EncoderConfig zapcore.EncoderConfig `json:"encoderConfig" yaml:"encoderConfig"` - // OutputPaths is a list of paths to write logging output to. See Open for - // details. + // OutputPaths is a list of URLs or file paths to write logging output to. + // See Open for details. OutputPaths []string `json:"outputPaths" yaml:"outputPaths"` - // ErrorOutputPaths is a list of paths to write internal logger errors to. + // ErrorOutputPaths is a list of URLs to write internal logger errors to. // The default is standard error. // // Note that this setting only affects internal errors; for sample code that diff --git a/vendor/go.uber.org/zap/doc.go b/vendor/go.uber.org/zap/doc.go index 3f16a8d4576f..8638dd1b9656 100644 --- a/vendor/go.uber.org/zap/doc.go +++ b/vendor/go.uber.org/zap/doc.go @@ -48,7 +48,7 @@ // "attempt", 3, // "backoff", time.Second, // ) -// sugar.Printf("failed to fetch URL: %s", "http://example.com") +// sugar.Infof("failed to fetch URL: %s", "http://example.com") // // By default, loggers are unbuffered. However, since zap's low-level APIs // allow buffering, calling Sync before letting your process exit is a good diff --git a/vendor/go.uber.org/zap/global.go b/vendor/go.uber.org/zap/global.go index d02232e39fa7..c1ac0507cd9b 100644 --- a/vendor/go.uber.org/zap/global.go +++ b/vendor/go.uber.org/zap/global.go @@ -31,7 +31,6 @@ import ( ) const ( - _stdLogDefaultDepth = 2 _loggerWriterDepth = 2 _programmerErrorTemplate = "You've found a bug in zap! Please file a bug at " + "https://github.com/uber-go/zap/issues/new and reference this error: %v" diff --git a/vendor/go.uber.org/zap/http_handler.go b/vendor/go.uber.org/zap/http_handler.go index f171c3847f4a..1b0ecaca9c15 100644 --- a/vendor/go.uber.org/zap/http_handler.go +++ b/vendor/go.uber.org/zap/http_handler.go @@ -48,11 +48,11 @@ func (lvl AtomicLevel) ServeHTTP(w http.ResponseWriter, r *http.Request) { switch r.Method { - case "GET": + case http.MethodGet: current := lvl.Level() enc.Encode(payload{Level: ¤t}) - case "PUT": + case http.MethodPut: var req payload if errmess := func() string { diff --git a/vendor/go.uber.org/zap/writer.go b/vendor/go.uber.org/zap/writer.go index 16f55ce4875c..86a709ab0be2 100644 --- a/vendor/go.uber.org/zap/writer.go +++ b/vendor/go.uber.org/zap/writer.go @@ -21,21 +21,33 @@ package zap import ( + "fmt" + "io" "io/ioutil" - "os" "go.uber.org/zap/zapcore" "go.uber.org/multierr" ) -// Open is a high-level wrapper that takes a variadic number of paths, opens or -// creates each of the specified files, and combines them into a locked +// Open is a high-level wrapper that takes a variadic number of URLs, opens or +// creates each of the specified resources, and combines them into a locked // WriteSyncer. It also returns any error encountered and a function to close // any opened files. // -// Passing no paths returns a no-op WriteSyncer. The special paths "stdout" and -// "stderr" are interpreted as os.Stdout and os.Stderr, respectively. +// Passing no URLs returns a no-op WriteSyncer. Zap handles URLs without a +// scheme and URLs with the "file" scheme. Third-party code may register +// factories for other schemes using RegisterSink. +// +// URLs with the "file" scheme must use absolute paths on the local +// filesystem. No user, password, port, fragments, or query parameters are +// allowed, and the hostname must be empty or "localhost". +// +// Since it's common to write logs to the local filesystem, URLs without a +// scheme (e.g., "/var/log/foo.log") are treated as local file paths. Without +// a scheme, the special paths "stdout" and "stderr" are interpreted as +// os.Stdout and os.Stderr. When specified without a scheme, relative file +// paths also work. func Open(paths ...string) (zapcore.WriteSyncer, func(), error) { writers, close, err := open(paths) if err != nil { @@ -47,33 +59,24 @@ func Open(paths ...string) (zapcore.WriteSyncer, func(), error) { } func open(paths []string) ([]zapcore.WriteSyncer, func(), error) { - var openErr error writers := make([]zapcore.WriteSyncer, 0, len(paths)) - files := make([]*os.File, 0, len(paths)) + closers := make([]io.Closer, 0, len(paths)) close := func() { - for _, f := range files { - f.Close() + for _, c := range closers { + c.Close() } } + + var openErr error for _, path := range paths { - switch path { - case "stdout": - writers = append(writers, os.Stdout) - // Don't close standard out. - continue - case "stderr": - writers = append(writers, os.Stderr) - // Don't close standard error. + sink, err := newSink(path) + if err != nil { + openErr = multierr.Append(openErr, fmt.Errorf("couldn't open sink %q: %v", path, err)) continue } - f, err := os.OpenFile(path, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0644) - openErr = multierr.Append(openErr, err) - if err == nil { - writers = append(writers, f) - files = append(files, f) - } + writers = append(writers, sink) + closers = append(closers, sink) } - if openErr != nil { close() return writers, nil, openErr diff --git a/vendor/go.uber.org/zap/zapcore/field.go b/vendor/go.uber.org/zap/zapcore/field.go index 6a5e33e2f798..ae772e4a1707 100644 --- a/vendor/go.uber.org/zap/zapcore/field.go +++ b/vendor/go.uber.org/zap/zapcore/field.go @@ -160,7 +160,7 @@ func (f Field) AddTo(enc ObjectEncoder) { case NamespaceType: enc.OpenNamespace(f.Key) case StringerType: - enc.AddString(f.Key, f.Interface.(fmt.Stringer).String()) + err = encodeStringer(f.Key, f.Interface, enc) case ErrorType: encodeError(f.Key, f.Interface.(error), enc) case SkipType: @@ -199,3 +199,14 @@ func addFields(enc ObjectEncoder, fields []Field) { fields[i].AddTo(enc) } } + +func encodeStringer(key string, stringer interface{}, enc ObjectEncoder) (err error) { + defer func() { + if v := recover(); v != nil { + err = fmt.Errorf("PANIC=%v", v) + } + }() + + enc.AddString(key, stringer.(fmt.Stringer).String()) + return +} diff --git a/vendor/go.uber.org/zap/zapcore/json_encoder.go b/vendor/go.uber.org/zap/zapcore/json_encoder.go index 1006ba2b1198..9aec4eada31c 100644 --- a/vendor/go.uber.org/zap/zapcore/json_encoder.go +++ b/vendor/go.uber.org/zap/zapcore/json_encoder.go @@ -44,10 +44,15 @@ func getJSONEncoder() *jsonEncoder { } func putJSONEncoder(enc *jsonEncoder) { + if enc.reflectBuf != nil { + enc.reflectBuf.Free() + } enc.EncoderConfig = nil enc.buf = nil enc.spaced = false enc.openNamespaces = 0 + enc.reflectBuf = nil + enc.reflectEnc = nil _jsonPool.Put(enc) } @@ -56,6 +61,10 @@ type jsonEncoder struct { buf *buffer.Buffer spaced bool // include spaces after colons and commas openNamespaces int + + // for encoding generic values by reflection + reflectBuf *buffer.Buffer + reflectEnc *json.Encoder } // NewJSONEncoder creates a fast, low-allocation JSON encoder. The encoder @@ -124,13 +133,27 @@ func (enc *jsonEncoder) AddInt64(key string, val int64) { enc.AppendInt64(val) } +func (enc *jsonEncoder) resetReflectBuf() { + if enc.reflectBuf == nil { + enc.reflectBuf = bufferpool.Get() + enc.reflectEnc = json.NewEncoder(enc.reflectBuf) + + // For consistency with our custom JSON encoder. + enc.reflectEnc.SetEscapeHTML(false) + } else { + enc.reflectBuf.Reset() + } +} + func (enc *jsonEncoder) AddReflected(key string, obj interface{}) error { - marshaled, err := json.Marshal(obj) + enc.resetReflectBuf() + err := enc.reflectEnc.Encode(obj) if err != nil { return err } + enc.reflectBuf.TrimNewline() enc.addKey(key) - _, err = enc.buf.Write(marshaled) + _, err = enc.buf.Write(enc.reflectBuf.Bytes()) return err } @@ -213,12 +236,14 @@ func (enc *jsonEncoder) AppendInt64(val int64) { } func (enc *jsonEncoder) AppendReflected(val interface{}) error { - marshaled, err := json.Marshal(val) + enc.resetReflectBuf() + err := enc.reflectEnc.Encode(val) if err != nil { return err } + enc.reflectBuf.TrimNewline() enc.addElementSeparator() - _, err = enc.buf.Write(marshaled) + _, err = enc.buf.Write(enc.reflectBuf.Bytes()) return err } diff --git a/vendor/go.uber.org/zap/zapcore/memory_encoder.go b/vendor/go.uber.org/zap/zapcore/memory_encoder.go index 5c46bc13d6f1..dfead0829d67 100644 --- a/vendor/go.uber.org/zap/zapcore/memory_encoder.go +++ b/vendor/go.uber.org/zap/zapcore/memory_encoder.go @@ -43,7 +43,7 @@ func NewMapObjectEncoder() *MapObjectEncoder { // AddArray implements ObjectEncoder. func (m *MapObjectEncoder) AddArray(key string, v ArrayMarshaler) error { - arr := &sliceArrayEncoder{} + arr := &sliceArrayEncoder{elems: make([]interface{}, 0)} err := v.MarshalLogArray(arr) m.cur[key] = arr.elems return err @@ -158,7 +158,7 @@ func (s *sliceArrayEncoder) AppendReflected(v interface{}) error { } func (s *sliceArrayEncoder) AppendBool(v bool) { s.elems = append(s.elems, v) } -func (s *sliceArrayEncoder) AppendByteString(v []byte) { s.elems = append(s.elems, v) } +func (s *sliceArrayEncoder) AppendByteString(v []byte) { s.elems = append(s.elems, string(v)) } func (s *sliceArrayEncoder) AppendComplex128(v complex128) { s.elems = append(s.elems, v) } func (s *sliceArrayEncoder) AppendComplex64(v complex64) { s.elems = append(s.elems, v) } func (s *sliceArrayEncoder) AppendDuration(v time.Duration) { s.elems = append(s.elems, v) }