*: log format for release-2.1 (#1625)

* *:Start swithing to the zap logger (#1422) Signed-off-by: nolouch <nolouch@gmail.com> * *: log format for schedule, scheduler, syncer, api (#1423) * log format for schedule, scheduler, syncer, api Signed-off-by: rleungx <rleungx@gmail.com> * pdctl, api: support hex format keys (#1309) pdctl, api: support hex format keys Signed-off-by: disksing <i@disksing.com> * *: log format for tools, client, pkg, table (#1424) * log format for tools, client, pkg, table, simulator Signed-off-by: rleungx <rleungx@gmail.com> * *: log format for server (#1431) * *: log format for server Signed-off-by: nolouch <nolouch@gmail.com> * *: log format for logutil, server/core (#1438) * *: log format for logutil,server/core * *: improve some logs (#1516) * improve some logs Signed-off-by: Ryan Leung <rleungx@gmail.com> * log: do not add stack to error log (#1532) * pkg, tools: improve the log message (#1636) * pkg,tools: improve the log message Signed-off-by: nolouch <nolouch@gmail.com> * core: use hex format for region meta key (#1627) Signed-off-by: Ryan Leung <rleungx@gmail.com>= * address comments Signed-off-by: nolouch <nolouch@gmail.com> * address comments Signed-off-by: nolouch <nolouch@gmail.com>
tikv · Jul 17, 2019 · 165e4cb · 165e4cb
1 parent 5059637
commit 165e4cb
Show file tree

Hide file tree

Showing 93 changed files with 2,268 additions and 434 deletions.
diff --git a/.gitignore b/.gitignore
@@ -7,3 +7,4 @@ default.pd
 .DS_Store
 tags
 /.retools/
+default*
diff --git a/Gopkg.lock b/Gopkg.lock
diff --git a/Gopkg.toml b/Gopkg.toml
@@ -43,3 +43,11 @@
 [[override]]
   name = "github.com/BurntSushi/toml"
   revision = "3012a1dbe2e4bd1391d42b32f0577cb7bbc7f005"
+
+[[constraint]]
+  name = "github.com/pingcap/log"
+  branch = "master"
+
+[[constraint]]
+  name = "go.uber.org/zap"
+  version = "1.9.1"
diff --git a/client/client.go b/client/client.go
@@ -25,8 +25,9 @@ import (
 	"github.com/opentracing/opentracing-go"
 	"github.com/pingcap/kvproto/pkg/metapb"
 	"github.com/pingcap/kvproto/pkg/pdpb"
+	log "github.com/pingcap/log"
 	"github.com/pkg/errors"
-	log "github.com/sirupsen/logrus"
+	"go.uber.org/zap"
 	"golang.org/x/net/context"
 	"google.golang.org/grpc"
 	"google.golang.org/grpc/credentials"
@@ -139,7 +140,7 @@ type SecurityOption struct {
 
 // NewClient creates a PD client.
 func NewClient(pdAddrs []string, security SecurityOption) (Client, error) {
-	log.Infof("[pd] create pd client with endpoints %v", pdAddrs)
+	log.Info("[pd] create pd client with endpoints", zap.Strings("pd-address", pdAddrs))
 	ctx, cancel := context.WithCancel(context.Background())
 	c := &client{
 		urls:          addrsToUrls(pdAddrs),
@@ -158,7 +159,7 @@ func NewClient(pdAddrs []string, security SecurityOption) (Client, error) {
 	if err := c.updateLeader(); err != nil {
 		return nil, err
 	}
-	log.Infof("[pd] init cluster id %v", c.clusterID)
+	log.Info("[pd] init cluster id", zap.Uint64("cluster-id", c.clusterID))
 
 	c.wg.Add(3)
 	go c.tsLoop()
@@ -185,7 +186,7 @@ func (c *client) initClusterID() error {
 			members, err := c.getMembers(timeoutCtx, u)
 			timeoutCancel()
 			if err != nil || members.GetHeader() == nil {
-				log.Errorf("[pd] failed to get cluster id: %v", err)
+				log.Error("[pd] failed to get cluster id", zap.Error(err))
 				continue
 			}
 			c.clusterID = members.GetHeader().GetClusterId()
@@ -241,7 +242,7 @@ func (c *client) switchLeader(addrs []string) error {
 		return nil
 	}
 
-	log.Infof("[pd] leader switches to: %v, previous: %v", addr, oldLeader)
+	log.Info("[pd] switch leader", zap.String("new-leader", addr), zap.String("old-leader", oldLeader))
 	if _, err := c.getOrCreateGRPCConn(addr); err != nil {
 		return err
 	}
@@ -326,7 +327,7 @@ func (c *client) leaderLoop() {
 		}
 
 		if err := c.updateLeader(); err != nil {
-			log.Errorf("[pd] failed updateLeader: %v", err)
+			log.Error("[pd] failed updateLeader", zap.Error(err))
 		}
 	}
 }
@@ -384,7 +385,7 @@ func (c *client) tsLoop() {
 					return
 				default:
 				}
-				log.Errorf("[pd] create tso stream error: %v", err)
+				log.Error("[pd] create tso stream error", zap.Error(err))
 				c.ScheduleCheckLeader()
 				cancel()
 				c.revokeTSORequest(errors.WithStack(err))
@@ -430,7 +431,7 @@ func (c *client) tsLoop() {
 				return
 			default:
 			}
-			log.Errorf("[pd] getTS error: %v", err)
+			log.Error("[pd] getTS error", zap.Error(err))
 			c.ScheduleCheckLeader()
 			cancel()
 			stream, cancel = nil, nil
@@ -512,7 +513,7 @@ func (c *client) Close() {
 	defer c.connMu.Unlock()
 	for _, cc := range c.connMu.clientConns {
 		if err := cc.Close(); err != nil {
-			log.Errorf("[pd] failed close grpc clientConn: %v", err)
+			log.Error("[pd] failed close grpc clientConn", zap.Error(err))
 		}
 	}
 }

diff --git 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,22 +41,32 @@ func main() {
 
 	if cfg.Version {
 		server.PrintPDInfo()
-		os.Exit(0)
+		exit(0)
 	}
 
 	defer logutil.LogPanic()
 
 	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/etcdutil/etcdutil.go b/pkg/etcdutil/etcdutil.go
@@ -22,8 +22,9 @@ import (
 	"github.com/coreos/etcd/clientv3"
 	"github.com/coreos/etcd/etcdserver"
 	"github.com/coreos/etcd/pkg/types"
+	log "github.com/pingcap/log"
 	"github.com/pkg/errors"
-	log "github.com/sirupsen/logrus"
+	"go.uber.org/zap"
 )
 
 const (
@@ -59,7 +60,7 @@ func CheckClusterID(localClusterID types.ID, um types.URLsMap, tlsConfig *tls.Co
 		trp.CloseIdleConnections()
 		if gerr != nil {
 			// Do not return error, because other members may be not ready.
-			log.Error(gerr)
+			log.Error("failed to get cluster from remote", zap.Error(gerr))
 			continue
 		}
 

diff --git a/pkg/logutil/log.go b/pkg/logutil/log.go
@@ -19,14 +19,16 @@ import (
 	"os"
 	"path"
 	"runtime"
-	"runtime/debug"
 	"strings"
 	"sync"
 
 	"github.com/coreos/etcd/raft"
 	"github.com/coreos/pkg/capnslog"
+	zaplog "github.com/pingcap/log"
 	"github.com/pkg/errors"
 	log "github.com/sirupsen/logrus"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
 	"google.golang.org/grpc/grpclog"
 	lumberjack "gopkg.in/natefinch/lumberjack.v2"
 )
@@ -144,6 +146,23 @@ func StringToLogLevel(level string) log.Level {
 	return defaultLogLevel
 }
 
+// StringToZapLogLevel translates log level string to log level.
+func StringToZapLogLevel(level string) zapcore.Level {
+	switch strings.ToLower(level) {
+	case "fatal":
+		return zapcore.FatalLevel
+	case "error":
+		return zapcore.ErrorLevel
+	case "warn", "warning":
+		return zapcore.WarnLevel
+	case "debug":
+		return zapcore.DebugLevel
+	case "info":
+		return zapcore.InfoLevel
+	}
+	return zapcore.InfoLevel
+}
+
 // textFormatter is for compatibility with ngaut/log
 type textFormatter struct {
 	DisableTimestamp bool
@@ -196,7 +215,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 +257,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() {
@@ -271,6 +290,6 @@ func InitLogger(cfg *LogConfig) error {
 // Commonly used with a `defer`.
 func LogPanic() {
 	if e := recover(); e != nil {
-		log.Fatalf("panic: %v, stack: %s", e, string(debug.Stack()))
+		zaplog.Fatal("panic", zap.Reflect("recover", e))
 	}
 }
diff --git a/pkg/logutil/log_test.go b/pkg/logutil/log_test.go
@@ -20,7 +20,9 @@ import (
 
 	"github.com/coreos/pkg/capnslog"
 	. "github.com/pingcap/check"
+	zaplog "github.com/pingcap/log"
 	log "github.com/sirupsen/logrus"
+	"go.uber.org/zap/zapcore"
 )
 
 const (
@@ -51,9 +53,19 @@ func (s *testLogSuite) TestStringToLogLevel(c *C) {
 	c.Assert(StringToLogLevel("whatever"), Equals, log.InfoLevel)
 }
 
+func (s *testLogSuite) TestStringToZapLogLevel(c *C) {
+	c.Assert(StringToZapLogLevel("fatal"), Equals, zapcore.FatalLevel)
+	c.Assert(StringToZapLogLevel("ERROR"), Equals, zapcore.ErrorLevel)
+	c.Assert(StringToZapLogLevel("warn"), Equals, zapcore.WarnLevel)
+	c.Assert(StringToZapLogLevel("warning"), Equals, zapcore.WarnLevel)
+	c.Assert(StringToZapLogLevel("debug"), Equals, zapcore.DebugLevel)
+	c.Assert(StringToZapLogLevel("info"), Equals, zapcore.InfoLevel)
+	c.Assert(StringToZapLogLevel("whatever"), Equals, zapcore.InfoLevel)
+}
+
 // 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 +88,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)
+}