weather/pkg/logger/logger.go

package logger

import (
	"bytes"
	"io"
	"io/ioutil"
	"net/http"
	"os"
	"os/signal"
	"syscall"

	"go.elastic.co/apm/module/apmzap"
	"go.elastic.co/ecszap"
	"go.uber.org/zap"
	"go.uber.org/zap/zapcore"
	"gopkg.in/natefinch/lumberjack.v2"
)

// available level are
// DebugLevel
// InfoLevel
// WarnLevel
// ErrorLevel
// DPanicLevel
// PanicLevel
// FatalLevel

//WeatherLogger custom logger with totation and http Request and Response capability
type WeatherLogger struct {
	*zap.Logger
	Level zap.AtomicLevel
}

//NewLogger create new named logger
func NewLogger(loggerName, logPath string, level zap.AtomicLevel) *WeatherLogger {
	rotationPolicy := &lumberjack.Logger{
		Filename:   logPath,
		MaxSize:    5, // megabytes
		MaxBackups: 2, // number of backup
		// MaxAge:     28,   // days
		Compress: true, // disabled by default
	}

	rotateCatcher(rotationPolicy)

	encoderConfig := ecszap.EncoderConfig{
		EncodeLevel:      zapcore.CapitalLevelEncoder,
		EncodeDuration:   zapcore.MillisDurationEncoder,
		EncodeCaller:     ecszap.FullCallerEncoder,
		EnableStackTrace: false,
	}

	// log enabled by atomic level and error priority
	errorPriority := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
		return lvl >= level.Level() && lvl >= zapcore.ErrorLevel
	})
	// log enabled by atomic level and low priority
	lowPriority := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
		return lvl >= level.Level() && lvl < zapcore.ErrorLevel
	})
	consoleDebugging := zapcore.Lock(os.Stdout)
	consoleErrors := zapcore.Lock(os.Stderr)
	consoleEncoder := zapcore.NewConsoleEncoder(zap.NewDevelopmentEncoderConfig())

	core := zapcore.NewTee(
		ecszap.NewCore(encoderConfig, zapcore.AddSync(rotationPolicy), level),

		zapcore.NewCore(consoleEncoder, consoleDebugging, lowPriority),
		zapcore.NewCore(consoleEncoder, consoleErrors, errorPriority),
	)

	logger := zap.New(core, zap.AddCaller())

	return &WeatherLogger{
		Logger: logger.Named(loggerName),
		Level:  level,
	}
}

//HTTPLogHandler http handler to log http request and http response
func (wl *WeatherLogger) HTTPLogHandler(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		ww := ResponseWriter{
			ResponseWriter: w,
		}
		wl.logHTTPRequest(r)
		next.ServeHTTP(&ww, r)
		wl.logHTTPResponse(ww)
	})
}

type readCloser struct {
	io.Reader
	io.Closer
}

func useTeeReader(rc io.ReadCloser, w io.Writer) io.ReadCloser {
	tee := io.TeeReader(rc, w)
	teeCloser := readCloser{tee, rc}
	return teeCloser
}

//logHTTPRequest print request information
func (wl *WeatherLogger) logHTTPRequest(r *http.Request) {
	var buf bytes.Buffer
	b, err := ioutil.ReadAll(io.TeeReader(r.Body, &buf))
	wl.handleError(err)
	r.Body = readCloser{&buf, r.Body}
	traceContextFields := apmzap.TraceContext(r.Context())

	// var buf bytes.Buffer
	// var buf2 bytes.Buffer
	// b, err := io.Copy(io.MultiWriter(&buf, &buf2), r.Body)
	// wl.handleError(err)
	// r.Body = readCloser{&buf2, r.Body}

	wl.Logger.With(traceContextFields...).Debug("Request",
		zap.String("http.request.method", r.Method),
		zap.ByteString("http.request.body.content", b),
		zap.Int("http.request.body.bytes", len(b)),
		// zap.Int64("http.request.bytes", r.Header ContentLength), // total body+header len
		// zap.String(""),
		// zap.String(""),
		// zap.String(""),
	)
}

//logHTTPResponse print response information
func (wl *WeatherLogger) logHTTPResponse(ww ResponseWriter) {
	wl.Logger.Debug("Response",
		zap.Int("http.response.status_code", ww.Status),
		zap.Int("http.response.body.bytes", ww.Length),
	)
}

//rotateCatcher force log rotation on SIGUSR1 signal
func rotateCatcher(rotationPolicy *lumberjack.Logger) {
	c := make(chan os.Signal, 1)
	signal.Notify(c, syscall.SIGUSR1)
	go func() {
		for {
			<-c
			rotationPolicy.Rotate()
		}
	}()
}

//handleError generic fatal error
func (wl *WeatherLogger) handleError(err error) {
	if err != nil {
		wl.Logger.Fatal("Logger error", zap.Error(err))
	}
}