はじめに

go の net/http の middleware として rs/zerolog を使う方法をまとめます。
rs/zerolog は構造化されたログを柔軟なフォーマットで高速に吐き出すことができる Logger です。

middleware として rs/zerolog を使う

go の net/http の middleware と書きましたが go-chi/chi という net/http に準拠した薄い router frameworkを利用します。

framework を使うことは必須ではないのですが、少し規模が大きくなるといつも似たような framework を自作していることに気付き、最近は最初から使うことが増えました。

go-chi/chi で middleware を stack する server を作る

go-chi/chi の readme にある通り NewRouter() で router のインスタンスを作り、そこに middleware を stack していきます。

ZeroLogger と書かれている middleware を自作します。

package main

import (
    "net/http"

    "github.com/go-chi/chi"
    "github.com/go-chi/chi/middleware"
)

func main() {
    r := chi.NewRouter()
    r.Use(middleware.RequestID)
    r.Use(middleware.RealIP)
    r.Use(ZeroLogger) // ← ZeroLogger を作る

    r.Get("/", func(w http.ResponseWriter, r *http.Request) {
        w.Write([]byte("welcome"))
    })
    http.ListenAndServe(":5050", r)
}

net/http の middleware として rs/zerolog を利用する

net/http の middleware を実装するには以下のような func(http.Handler) http.Handler 型を持っている必要があります。

func Middleware(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        next.ServeHTTP(w, r)
    })
}

今回はこのサイトを参考に io.MultiWriter を使って標準出力とファイルにログを吐きます。

ファイルは natefinch/lumberjack を使ってログローテートしています。

chi/middleware にある NewWrapResponseWriter() を使うと簡単に status code を取得できるので、少し雑ですが level を分けて Logging もできます。

package main

import (
    "fmt"
    "io"
    "net/http"
    "os"
    "time"

    "github.com/go-chi/chi/middleware"
    "github.com/rs/zerolog"

    "gopkg.in/natefinch/lumberjack.v2"
)

func ZeroLogger(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        zerolog.TimeFieldFormat = time.RFC3339Nano

        writer := &lumberjack.Logger{
            Filename:   "server.log",
            MaxSize:    10,
            MaxBackups: 5, // days
            MaxAge:     1, // days
            Compress:   true,
        }

        writers := io.MultiWriter(os.Stdout, writer)
        log := zerolog.New(writers).With().Timestamp().Logger()

        start := time.Now()
        var requestID string
        if reqID := r.Context().Value(middleware.RequestIDKey); reqID != nil {
            requestID = reqID.(string)
        }

        ww := middleware.NewWrapResponseWriter(w, r.ProtoMajor)
        next.ServeHTTP(ww, r)

        latency := time.Since(start)

        scheme := "http"
        if r.TLS != nil {
            scheme = "https"
        }

        switch {
        case ww.Status() < 500:
            log.Info().
                Time("received_time", start).
                Int64(fmt.Sprint("latency_time"), latency.Nanoseconds()).
                Int("status", ww.Status()).
                Str("scheme", scheme).
                Str("host", r.Host).
                Str("protocol", r.Proto).
                Str("method", r.Method).
                Str("remoteIP", r.RemoteAddr).
                Str("request-id", requestID).
                Str("request", r.RequestURI).
                Str("agent", r.UserAgent()).
                Int("bytes", ww.BytesWritten())
        default:
            log.Error().
                Time("received_time", start).
                Int64(fmt.Sprint("latency_time"), latency.Nanoseconds()).
                Int("status", ww.Status()).
                Str("scheme", scheme).
                Str("host", r.Host).
                Str("protocol", r.Proto).
                Str("method", r.Method).
                Str("remoteIP", r.RemoteAddr).
                Str("request-id", requestID).
                Str("request", r.RequestURI).
                Str("agent", r.UserAgent()).
                Int("bytes", ww.BytesWritten()).
        }

    })
}

まとめ

go の net/http の middleware として rs/zerolog を使う方法をまとめました。
次回は NewWrapResponseWriter() で status code を取得できるまでの流れを調べてみます。