[Golang] grpc + zap에서 closing log 제거하기(feat. zapfilter)

go에서 grpc 통신을 하면서 zap을 logger로 사용하면서 log level을 InfoLevel 이하로 하면 아래와 같은 로그가 보인다.

{"level":"info","message":"transport: loopyWriter.run returning. connection error: desc = \"transport is closing\"","system":"grpc","grpc_log":true}.

client와 rpc 연결이 끊겼다는건데, debug시에 분명 도움이 되는 로그이지만 현재 사용하는 환경에서 client가 요청하면 disconnect 를 호출해주고 있어서 해당 로그가 너무 자주 보여서 해당 로그를 없애려고 한다.

---

Easiest Solution

가장 쉬운 방법은 Log level 을 WarnLevel 이상으로 한다.

const (
	// DebugLevel logs are typically voluminous, and are usually disabled in
	// production.
	DebugLevel = zapcore.DebugLevel
	// InfoLevel is the default logging priority.
	InfoLevel = zapcore.InfoLevel
	// WarnLevel logs are more important than Info, but don't need individual
	// human review.
	WarnLevel = zapcore.WarnLevel
	// ErrorLevel logs are high-priority. If an application is running smoothly,
	// it shouldn't generate any error-level logs.
	ErrorLevel = zapcore.ErrorLevel
	// DPanicLevel logs are particularly important errors. In development the
	// logger panics after writing the message.
	DPanicLevel = zapcore.DPanicLevel
	// PanicLevel logs a message, then panics.
	PanicLevel = zapcore.PanicLevel
	// FatalLevel logs a message, then calls os.Exit(1).
	FatalLevel = zapcore.FatalLevel
)

zap 이 level 기반 logger 이기 때문에, info에 해당하는 해당 로그를 안보기 위해서 WarnLevel 이상으로 설정하면 자연스럽게 안보이게 된다.

하지만 그렇게 하게되면, 일반적인 통신 info도 안보이기 때문에 현재 상황에서 사용하기에는 좋지 않았다.

물론 WarnLevel로 해두고, 중간에 interceptor를 이용해서 InfoLevel 에 해당하는 로그 중 원하는 메시지를 포함하고 있으면 로그를 만들어주는 방법도 있다.

---

The Choosen Solution

다른 방법으로 해결하기로 했는데, 그 과정에서 사용하게 된게 zapfilter.

install

$ go get -u moul.io/zapfilter

$ go get -u go.uber.org/zap
$ go get -u go.uber.org/zap/zapcore

usage

var skipLogMessage = []string{
	"loopyWriter exiting with error: transport closed by client",
	"Closing: EOF",
	"Closing: connection error",
}

func isSkipLogMessage(message string) bool {
	for _, skipMessage := range skipLogMessage {
		if strings.Contains(message, skipMessage) {
			return true
		}
	}
	return false
}

func NewLogger() *zap.Logger {
  encodingConfig := zap.NewProductionEncoderConfig()

  core := zapcore.NewCore(
      zapcore.NewJSONEncoder(encodingConfig),
      zapcore.AddSync(os.Stdout),
      zap.InfoLevel,
   )

  filteringCore := zapfilter.NewFilteringCore(core, func(entry zapcore.Entry, fields []zapcore.Field) bool {
      if entry.Level == zap.InfoLevel {
          return !isSkipLogMessage(entry.Message)
      }
      return true
  })

  return zap.New(filteringCore, zap.AddCallerSkip(1))
}

위와 같이 zap.Core에 filter를 이용해서 zpacore.Entry의 값을 읽어와서 로직을 수행해 줄 수 있다.

---

Result

지속적으로 보이던 노이즈 같던 로그가 안보이니까 마음이 편하다.