前言: 一个扩展性强, 高性能的日志有助于程序员快速debug, 回溯线上问题. 本文致力于最快速地带你上手zap日志结构.看完此教程, 你将有才能独立开发一套出极简的,但功能齐全(包括日志等级/时刻, 日志生成的文件/函数/行号, 带恳求链路 trace id 并打通http与grpc 服务)的日志系统. 希望你拥有linux 和 grpc的运用经验, 假如不熟悉可以参考我别的两篇文章: 保姆级从0到1讲解go长途开发环境建立(从Docker安装到运用Goland长途部署和调试) 和 花5分钟写个 grpc 微服务

新建工程

创立新目录 zap_demo 在该目录下翻开指令行输入:

go mod init zap_demo
go mod tidy

随后创立各目录与文件如下:

-- zap_demo
    --client 
        --client.go // 调用http接口函数
    -- http_server
        --hello_handler.go // http handler
    -- main
        -- main.go // 发动 http 和 grpc handler的进口
    -- log
        -- simple_zap.log // 程序运转时主动生成
    -- proto
        -- chat.pb // pb 文件
        -- chat.pb.go // 运用 protoc 生成的 pb.go 文件, 不用新建, 主动生成
        -- chat.go // 实现 grpc service 的函数文件
    -- simple_zap
        -- zap 日志结构的装备信息
    --go.mod
        --go.sum

simple_zap.go

先来看 zap 的中心装备, 各个地方我都写了具体的注释。

package simple_zap
import (
   "context"
   "go.uber.org/zap"
   "go.uber.org/zap/zapcore"
   "gopkg.in/natefinch/lumberjack.v2"
)
const loggerCtxKey = "logger_ctx_key"
var Logger *zap.Logger
func init() {
   hook := lumberjack.Logger{
      Filename:   "/home/zap_demo/log/simple_zap.log",
      MaxSize:    1,    // 日志文件最大体积(MB)
      MaxAge:     1,    //最多保持几天的日志
      MaxBackups: 1,    //最多保持多少个日志文件
      LocalTime:  true, // 运用本地时刻, 而不是UTC时刻
      Compress:   true, // 紧缩日志
   }
   encoder_config := zapcore.EncoderConfig{
      MessageKey:     "msg",                          // 日志内容 的 key
      LevelKey:       "level",                        // 日志 level 的 key
      TimeKey:        "time",                         // 日志时刻 的 key
      CallerKey:      "lineNum",                      // 日志发生的文件及其行数 的 key
      FunctionKey:    "func",                         // 日志发生的函数 的 key
      LineEnding:     zapcore.DefaultLineEnding,      // 回车符换行
      EncodeLevel:    zapcore.LowercaseLevelEncoder,  // level小写: info,debug,warn等 而不是 Info, Debug,Warn等
      EncodeTime:     zapcore.ISO8601TimeEncoder,     // 时刻格局: "2006-01-02T15:04:05.000Z0700"
      EncodeDuration: zapcore.SecondsDurationEncoder, // 时刻戳用float64型,更加准确, 另一种是NanosDurationEncoder int64
      EncodeCaller:   zapcore.ShortCallerEncoder,     // 发生日志文件的途径格局: 包名/文件名:行号
   }
   caller := zap.AddCaller() //日志打印输出 文件名, 行号, 函数名
   development := zap.Development()  // 可输出 dpanic, panic 等级的日志
   field := zap.Fields() // 负责给日志生成一个个 k-v 对
   var syncers []zapcore.WriteSyncer // io writer
   syncers = append(syncers, zapcore.AddSync(&hook))
   atomic_level := zap.NewAtomicLevel()  // 设置日志 level
   atomic_level.SetLevel(zap.DebugLevel) // 打印 debug, info, warn,eror, depanic,panic,fetal 悉数等级日志
   core := zapcore.NewCore(zapcore.NewJSONEncoder(encoder_config), zapcore.NewMultiWriteSyncer(syncers...), atomic_level)
   Logger = zap.New(core, caller, development, field)
}
// 给 ctx 注入一个 looger, logger 中包括Field(内含日志打印的 k-v对)
func NewCtx(ctx context.Context, fields ...zapcore.Field) context.Context {
   return context.WithValue(ctx, loggerCtxKey, WithCtx(ctx).With(fields...))
}
//  
尝试从 context 中获取带有 traceId Field的 logge
func WithCtx(ctx context.Context) *zap.Logger {
   if ctx == nil {
      return Logger
   }
   ctx_logger, ok := ctx.Value(loggerCtxKey).(*zap.Logger)
   if ok {
      return ctx_logger
   }
   return Logger
}

proto

chat.proto 文件
chat.proto十分简略, 只界说了一个ChatService服务, 服务里面只要一个函数SayHello

syntax = "proto3";
package proto;
option go_package="/";
// 界说 message
message ChatMessage {
 string body = 1;
}
// 界说 service
service ChatService {
 rpc SayHello(ChatMessage ) returns (ChatMessage ) {}
}

随后运用 protoc 工具生成 对应的 pb.go 文件, 在 simple_zap 目录下履行:

 protoc --go_out=plugins=grpc:proto  --proto_path= proto/simple_server.proto

接着编写 chat.go 文件:

package __
import (
  "context"
  "zap_demo/simple_zap"
)
type Server struct {
}
func (s *Server) SayHello(ctx context.Context, in *ChatMessage) (*ChatMessage, error) {
  simple_zap.WithCtx(ctx).Sugar().Info("Reach SayHello service!")
  return &ChatMessage{Body: "Hello From SayHello service!"}, nil
}

chat.go里面的 SayHello 函数也很简略, 只打印了一条日志就return了。打印日志的目的是为了验证 traceId可以跨服务运用。

http_server/hello_handler.go

hello_handler.go 很简略, 界说了一个 HelloHandler, 只打印了一行日志。
HelloToGrpcHandler 也很简略, 仅仅是做了一次 grpc 恳求。但有个特别的地方,就是 context.WithValue带着的 信息不能通过 grpc 进行传递, 所以这儿特意多了一层 metadata.NewOutgoingContext 将 traceId 塞入一个 新的 context。在后续的 grpc 拦截器中也会这样取出来。

package http_server
import (
  "google.golang.org/grpc"
  "google.golang.org/grpc/metadata"
  "net/http"
  proto "zap_demo/proto"
  "zap_demo/simple_zap"
)
func HelloHandler(w http.ResponseWriter, r *http.Request) {
  simple_zap.WithCtx(r.Context()).Sugar().Info("Reach HelloHandler.")
}
func HelloToGrpcHandler(w http.ResponseWriter, r *http.Request) {
  simple_zap.WithCtx(r.Context()).Sugar().Info("Reach HelloToGrpcHandler.")
  var conn *grpc.ClientConn
  conn, err := grpc.Dial(":8000", grpc.WithInsecure())
  if err != nil {
     simple_zap.WithCtx(r.Context()).Sugar().Error(err)
  }
  defer conn.Close()
  // 获得一个 ChatService 的 client
  c := proto.NewChatServiceClient(conn)
  // grpc 调用长途的 SayHello
  trace_id := r.Context().Value("traceId").(string)
  grpc_ctx := metadata.NewOutgoingContext(r.Context(), metadata.Pairs("traceId", trace_id))
  response, err := c.SayHello(grpc_ctx, &proto.ChatMessage{Body: "Hello From Client!"})
  if err != nil {
     simple_zap.WithCtx(r.Context()).Sugar().Warn(err)
  }
  simple_zap.WithCtx(r.Context()).Sugar().Debugf("Response from server: %s", response.Body)
}

main/mian.go

main 函数主要是发动 http 与 grpc 服务。为了加上traceId, 咱们特意给 http 与 grpc 服务加上了拦截器。
grpc的拦截器比较特别, 这是因为 context.WithValue 不能通过 grpc 进行传递, 只能通过 metadata.NewOutgoingContext 将 traceId 塞入一个 新的 context, 所以这儿多做了一层取traceId和从头依据traceId生成一个新 looger 并塞入 context的操作。

package main
import (
   "context"
   "fmt"
   "github.com/gorilla/mux"
   "go.uber.org/zap"
   "google.golang.org/grpc"
   "google.golang.org/grpc/metadata"
   "net"
   "net/http"
   "zap_demo/http_server"
   proto "zap_demo/proto"
   "zap_demo/simple_zap"
   "github.com/google/uuid"
)
// http 拦截器, 给 context 注入一个带 traceId的 拦截器
func traceIdInterceptor(next http.Handler) http.Handler {
   return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
      trace_id := uuid.New().String()
      ctx := simple_zap.NewCtx(r.Context(), zap.String("traceId", trace_id)) // 给 ctx 注入一个 Field(内含日志打印的 k-v对, k 为 "traceId", v 就是 traceId)
      ctx = context.WithValue(ctx, "traceId", trace_id)                      // 给 ctx 注入 withValue k-v 对, 用户 grpc 调用时取出 traceId, 通过
      r2 := r.WithContext(ctx)
      next.ServeHTTP(w, r2)
   })
}
// grpc 拦截器, 尝试获取 traceId
func unaryTraceIdIterceptor() grpc.UnaryServerInterceptor {
   return func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (resp interface{}, err error) {
      md, ok := metadata.FromIncomingContext(ctx)
      if ok {
         trace_id := md.Get("traceId")[0]
         ctx = simple_zap.NewCtx(ctx, zap.String("traceId", trace_id))
      } else {
         trace_id := uuid.New().String()
         ctx = simple_zap.NewCtx(ctx, zap.String("traceId", trace_id))
      }
      resp, err = handler(ctx, req)
      return resp, err
   }
}
func main() {
   //http server
   r := mux.NewRouter()
   r.Use(traceIdInterceptor)
   r.HandleFunc("/hello", http_server.HelloHandler)
   r.HandleFunc("/hello_to_grpc", http_server.HelloToGrpcHandler)
   http.Handle("/", r)
   http_err_chan := make(chan error)
   go func() {
      http_err_chan <- http.ListenAndServe(":2000", nil)
      fmt.Println("err http")
   }()
   // grpc server
   lis, err := net.Listen("tcp", ":8000")
   if err != nil {
      fmt.Println("Fail to listen: %v", err)
   }
   s := proto.Server{}
   grpcServer := grpc.NewServer(grpc.UnaryInterceptor(unaryTraceIdIterceptor()))
   proto.RegisterChatServiceServer(grpcServer, &s)
   grpc_err_chan := make(chan error)
   go func() {
      grpc_err_chan <- grpcServer.Serve(lis)
   }()
   err = <-grpc_err_chan
   if err != nil {
      fmt.Println(err)
   }
}

client/client.go

client.go 就很简略了, 直接调用了两个http接口, 其间第二个http handler 中会做一次grpc 恳求。

package main
import (
   "context"
   "net/http"
   "zap_demo/simple_zap"
)
func main() {
   _, err := http.Get("http://localhost:2000/hello")
   if err != nil {
      simple_zap.WithCtx(context.Background()).Sugar().Warn(err)
      return
   }
   _, err = http.Get("http://localhost:2000/hello_to_grpc")
   if err != nil {
      simple_zap.WithCtx(context.Background()).Sugar().Warn(err)
      return
   }
}

运转起来

先在 main 途径下输入

go run main.go

新开个指令行在 client 途径下输入

go run client.go

随后在 log 途径下可以看到新生成 simple_zap.log文件,
指令行输入

cat  simple_zap.log

你将会看到下面4条日志

{"level":"info","time":"2023-04-29T06:24:57.099Z","lineNum":"http_server/hello_handler.go:12","func":"zap_demo/http_server.HelloHandler","msg":"Reach HelloHandler.","traceId":"56a1b6d3-ed1b-4878-9145-d2263ae134fd"}
{"level":"info","time":"2023-04-29T06:24:57.100Z","lineNum":"http_server/hello_handler.go:16","func":"zap_demo/http_server.HelloToGrpcHandler","msg":"Reach HelloToGrpcHandler.","traceId":"e7b47bf7-7df8-459e-91bd-dd0fcd69b0d4"}
{"level":"info","time":"2023-04-29T06:24:57.101Z","lineNum":"proto/chat.go:12","func":"zap_demo/proto.(*Server).SayHello","msg":"Reach SayHello service!","traceId":"e7b47bf7-7df8-459e-91bd-dd0fcd69b0d4"}
{"level":"debug","time":"2023-04-29T06:24:57.101Z","lineNum":"http_server/hello_handler.go:38","func":"zap_demo/http_server.HelloToGrpcHandler","msg":"Response from server: Hello From SayHello service!","traceId":"e7b47bf7-7df8-459e-91bd-dd0fcd69b0d4"}

可以看到后3条日志的 traceId 相同, 说明链路追踪功能正常, 可以跨服务。

伟人的肩膀

github.com/apache/dubb…

github.com/uber-go/zap

github.com/gorilla/mux