From e56a541a40fdb5ed71a483840b50f5128fb0cf4b Mon Sep 17 00:00:00 2001 From: Hadley Rich Date: Fri, 27 Oct 2023 11:39:48 +1300 Subject: [PATCH] New logging middleware that captures response --- go.mod | 5 +-- go.sum | 2 -- main.go | 107 ++++++++++++++++++++++++++++++++++++++++++++------------ 3 files changed, 86 insertions(+), 28 deletions(-) diff --git a/go.mod b/go.mod index 842ea1b..12facea 100644 --- a/go.mod +++ b/go.mod @@ -2,10 +2,7 @@ module git.nice.net.nz/hads/snice go 1.21.3 -require ( - github.com/urfave/cli/v2 v2.25.7 - golang.org/x/exp v0.0.0-20231006140011-7918f672742d -) +require github.com/urfave/cli/v2 v2.25.7 require ( github.com/cpuguy83/go-md2man/v2 v2.0.2 // indirect diff --git a/go.sum b/go.sum index baced2c..54cdbc1 100644 --- a/go.sum +++ b/go.sum @@ -6,5 +6,3 @@ github.com/urfave/cli/v2 v2.25.7 h1:VAzn5oq403l5pHjc4OhD54+XGO9cdKVL/7lDjF+iKUs= github.com/urfave/cli/v2 v2.25.7/go.mod h1:8qnjx1vcq5s2/wpsqoZFndg2CE5tNFyrTvS6SinrnYQ= github.com/xrash/smetrics v0.0.0-20201216005158-039620a65673 h1:bAn7/zixMGCfxrRTfdpNzjtPYqr8smhKouy9mxVdGPU= github.com/xrash/smetrics v0.0.0-20201216005158-039620a65673/go.mod h1:N3UwUGtsrSj3ccvlPHLoLsHnpR27oXr4ZE984MbSER8= -golang.org/x/exp v0.0.0-20231006140011-7918f672742d h1:jtJma62tbqLibJ5sFQz8bKtEM8rJBtfilJ2qTU199MI= -golang.org/x/exp v0.0.0-20231006140011-7918f672742d/go.mod h1:ldy0pHrwJyGW56pPQzzkH36rKxoZW1tw7ZJpeKx+hdo= diff --git a/main.go b/main.go index 98e81ab..2a980ae 100644 --- a/main.go +++ b/main.go @@ -3,33 +3,97 @@ package main import ( "fmt" "log" + "log/slog" "net" "net/http" "os" - "strings" "time" "github.com/urfave/cli/v2" - "golang.org/x/exp/slog" ) -func serveLogger(logger *log.Logger, next http.Handler) http.Handler { +type ( + // struct for holding response details + responseData struct { + status int + size int + } + + // our http.ResponseWriter implementation + loggingResponseWriter struct { + http.ResponseWriter // compose original http.ResponseWriter + responseData *responseData + } +) + +func (r *loggingResponseWriter) Write(b []byte) (int, error) { + size, err := r.ResponseWriter.Write(b) // write response using original http.ResponseWriter + r.responseData.size += size // capture size + return size, err +} + +func (r *loggingResponseWriter) WriteHeader(statusCode int) { + r.ResponseWriter.WriteHeader(statusCode) // write status code using original http.ResponseWriter + r.responseData.status = statusCode // capture status code +} + +func WithLogging(h http.Handler) http.Handler { + loggingFn := func(w http.ResponseWriter, r *http.Request) { + start := time.Now() + + responseData := &responseData{ + status: 0, + size: 0, + } + lrw := loggingResponseWriter{ + ResponseWriter: w, // compose original http.ResponseWriter + responseData: responseData, + } + h.ServeHTTP(&lrw, r) // inject our implementation of http.ResponseWriter + + duration := time.Since(start) + + slog.Info("Request:", + slog.String("method", r.Method), + slog.String("path", r.RequestURI), + slog.String("url", r.URL.Path), + slog.String("host", r.Host), + slog.Int("status", responseData.status), + slog.Int64("duration", duration.Microseconds()), + slog.Int("size", responseData.size), + ) + + } + return http.HandlerFunc(loggingFn) +} + +func LoggingMiddleware(logger *slog.Logger, next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - remoteHost, _, _ := strings.Cut(r.RemoteAddr, ":") - logger.Printf("%v %v %v\n", remoteHost, r.Method, r.URL.Path) next.ServeHTTP(w, r) + logger.Info("Request:", + slog.String("method", r.Method), + slog.String("path", r.RequestURI), + slog.String("url", r.URL.Path), + slog.String("host", r.Host), + ) + }) } -func timeHandler(w http.ResponseWriter, r *http.Request) { - fmt.Fprint(w, time.Now().Format("02 Jan 2006 15:04:05 MST")) +func pingHandler(w http.ResponseWriter, r *http.Request) { + w.Write([]byte("OK")) } func main() { - // handler := slog.NewJSONHandler(os.Stdout, nil) - handler := slog.NewTextHandler(os.Stdout, nil) - slog.SetDefault(slog.New(handler)) - logger := slog.NewLogLogger(handler, slog.LevelError) + logLevel := &slog.LevelVar{} // INFO + + opts := slog.HandlerOptions{ + Level: logLevel, + } + logLevel.Set(slog.LevelDebug) + handler := slog.NewTextHandler(os.Stdout, &opts) + logger := slog.New(handler) + slog.SetDefault(logger) var host string var port string @@ -49,23 +113,21 @@ func main() { var addr string = host + ":" + port srv := &http.Server{ - Addr: addr, - ErrorLog: logger, + Addr: addr, } mux := http.NewServeMux() - mux.HandleFunc("/time", timeHandler) - fileHandler := serveLogger(logger, http.FileServer(http.Dir(directory))) + mux.Handle("/ping", http.HandlerFunc(pingHandler)) + fileHandler := http.FileServer(http.Dir(directory)) mux.Handle("/", fileHandler) - srv.Handler = mux + srv.Handler = WithLogging(mux) listener, err := net.Listen("tcp", addr) if err != nil { - logger.Println(err) + logger.Error("Listen error", err) } - scheme := "http://" - logger.Printf("Serving directory %q on %v%v", directory, scheme, listener.Addr()) + logger.Info(fmt.Sprintf("Serving directory %q on http://%v", directory, listener.Addr())) err = srv.Serve(listener) if err != nil { - logger.Println(err) + logger.Error("Serve error", err) } return nil }, @@ -81,7 +143,7 @@ func main() { &cli.StringFlag{ Name: "host", EnvVars: []string{"HOST"}, - Value: "127.0.0.1", + Value: "0.0.0.0", Usage: "Host to listen on", Destination: &host, }}, @@ -91,10 +153,11 @@ func main() { Aliases: []string{"hc"}, Usage: "Call healthcheck endpoint", Action: func(cCtx *cli.Context) error { - _, err := http.Get(fmt.Sprintf("http://127.0.0.1:%s/health", port)) + _, err := http.Get(fmt.Sprintf("http://127.0.0.1:%s/ping", port)) if err != nil { os.Exit(1) } + os.Exit(0) return nil }}}, Flags: []cli.Flag{