From: Dan Fuhry <dan@fuhry.com>
Date: Tue, 31 Dec 2024 01:34:19 +0000 (-0500)
Subject: utils/log: record body size, request duration, initialize status to 200
X-Git-Url: https://go.fuhry.dev/?a=commitdiff_plain;h=0d1a389d945aae85a8493947f061bcb4c29b972e;p=runtime.git

utils/log: record body size, request duration, initialize status to 200
---

diff --git a/utils/log/http.go b/utils/log/http.go
index de9330a..fe8a2ff 100644
--- a/utils/log/http.go
+++ b/utils/log/http.go
@@ -7,6 +7,7 @@ import (
 	"net/http"
 	"net/textproto"
 	"strings"
+	"time"
 )
 
 const (
@@ -16,17 +17,20 @@ const (
 	kPath          = "path"
 	kUserAgent     = "user_agent"
 	kStatusCode    = "status"
+	kTimeTaken     = "duration_ms"
+	kBytesWritten  = "response_size"
 )
 
 type statusRecorder struct {
 	http.ResponseWriter
 	http.Hijacker
 
-	Status int
+	Status       int
+	BytesWritten uint
 }
 
 type LoggingMiddleware struct {
-	Logger    Logger
+	Logger    coreLogger
 	ExtraFunc func(map[string]any)
 
 	extraRequestHeaders  []string
@@ -68,12 +72,15 @@ func (lm *LoggingMiddleware) HandlerFunc() http.HandlerFunc {
 func (lm *LoggingMiddleware) handle(w http.ResponseWriter, r *http.Request) {
 	ws := &statusRecorder{
 		ResponseWriter: w,
+		Status:         http.StatusOK,
 	}
 	if h, ok := w.(http.Hijacker); ok {
 		ws.Hijacker = h
 	}
 
+	startTime := time.Now().UnixMilli()
 	lm.h.ServeHTTP(ws, r)
+	respTime := time.Now().UnixMilli() - startTime
 
 	entry := map[string]any{
 		kRemoteAddress: r.RemoteAddr,
@@ -81,15 +88,17 @@ func (lm *LoggingMiddleware) handle(w http.ResponseWriter, r *http.Request) {
 		kMethod:        r.Method,
 		kPath:          r.URL.Path,
 		kStatusCode:    ws.Status,
+		kTimeTaken:     respTime,
+		kBytesWritten:  ws.BytesWritten,
 	}
 
 	for _, h := range lm.extraRequestHeaders {
-		hKey := strings.ReplaceAll("-", "_", h)
+		hKey := strings.ReplaceAll(h, "-", "_")
 		entry[hKey] = r.Header.Get(h)
 	}
 	for _, h := range lm.extraResponseHeaders {
-		hKey := strings.ReplaceAll("-", "_", h)
-		entry[hKey] = r.Header.Get(h)
+		hKey := strings.ReplaceAll(h, "-", "_")
+		entry[hKey] = w.Header().Get(h)
 	}
 	if lm.ExtraFunc != nil {
 		lm.ExtraFunc(entry)
@@ -107,6 +116,14 @@ func (r *statusRecorder) WriteHeader(status int) {
 }
 
 func (r *statusRecorder) Hijack() (net.Conn, *bufio.ReadWriter, error) {
-	r.Status = http.StatusSwitchingProtocols
+	if r.Status == 0 {
+		r.Status = http.StatusSwitchingProtocols
+	}
 	return r.Hijacker.Hijack()
 }
+
+func (r *statusRecorder) Write(buf []byte) (int, error) {
+	n, err := r.ResponseWriter.Write(buf)
+	r.BytesWritten += uint(n)
+	return n, err
+}