diff --git a/internal/server/logging_middleware.go b/internal/server/logging_middleware.go index 2c9d2ab..6d37e76 100644 --- a/internal/server/logging_middleware.go +++ b/internal/server/logging_middleware.go @@ -2,22 +2,65 @@ package server import ( "bufio" + "encoding/json" "errors" - "log/slog" + "io" "net" "net/http" + "strconv" + "strings" "time" ) +type LoggingMiddlewareLine struct { + Timestamp string `json:"@timestamp"` + Message string `json:"message"` + Client struct { + IP string `json:"ip"` + Port int `json:"port"` + } `json:"client"` + Log struct { + Level string `json:"level"` + } `json:"log"` + Event struct { + Duration int64 `json:"duration"` + } `json:"event"` + HTTP struct { + Request struct { + Method string `json:"method"` + MimeType string `json:"mime_type"` + Body struct { + Bytes int64 `json:"bytes"` + } `json:"body"` + } `json:"request"` + Response struct { + StatusCode int `json:"status_code"` + MimeType string `json:"mime_type"` + Body struct { + Bytes int64 `json:"bytes"` + } `json:"body"` + } `json:"response"` + } `json:"http"` + URL struct { + Domain string `json:"domain"` + Path string `json:"path"` + Query string `json:"query"` + Scheme string `json:"scheme"` + } `json:"url"` + UserAgent struct { + Original string `json:"original"` + } `json:"user_agent"` +} + type LoggingMiddleware struct { - logger *slog.Logger - next http.Handler + encoder *json.Encoder + next http.Handler } -func NewLoggingMiddleware(logger *slog.Logger, next http.Handler) *LoggingMiddleware { +func NewLoggingMiddleware(w io.Writer, next http.Handler) *LoggingMiddleware { return &LoggingMiddleware{ - logger: logger, - next: next, + encoder: json.NewEncoder(w), + next: next, } } @@ -31,23 +74,52 @@ func (h *LoggingMiddleware) ServeHTTP(w http.ResponseWriter, r *http.Request) { userAgent := r.Header.Get("User-Agent") reqContent := r.Header.Get("Content-Type") respContent := writer.Header().Get("Content-Type") - remoteAddr := r.Header.Get("X-Forwarded-For") - if remoteAddr == "" { - remoteAddr = r.RemoteAddr + + clientIP, clientPort := h.determineClientIPAndPort(r) + + line := LoggingMiddlewareLine{ + Timestamp: started.Format(time.RFC3339), + Message: "Request", + } + + line.Log.Level = "INFO" + line.Client.IP = clientIP + line.Client.Port = clientPort + line.Event.Duration = elapsed.Nanoseconds() + line.HTTP.Request.Body.Bytes = r.ContentLength + line.HTTP.Request.Method = r.Method + line.HTTP.Request.MimeType = reqContent + line.HTTP.Response.Body.Bytes = writer.bytesWritten + line.HTTP.Response.MimeType = respContent + line.HTTP.Response.StatusCode = writer.statusCode + line.URL.Domain = r.Host + line.URL.Path = r.URL.Path + line.URL.Query = r.URL.RawQuery + line.URL.Scheme = r.URL.Scheme + + line.UserAgent.Original = userAgent + + h.encoder.Encode(line) +} + +func (h *LoggingMiddleware) determineClientIPAndPort(r *http.Request) (string, int) { + ip, portStr, err := net.SplitHostPort(r.RemoteAddr) + if err != nil { + portStr = "0" + } + + port, err := strconv.Atoi(portStr) + if err != nil { + port = 0 + } + + forwardedIP := strings.Split(r.Header.Get("X-Forwarded-For"), ",")[0] + + if forwardedIP != "" { + return forwardedIP, port } - h.logger.Info("Request", - "path", r.URL.Path, - "status", writer.statusCode, - "dur", elapsed.Milliseconds(), - "method", r.Method, - "req_content_length", r.ContentLength, - "req_content_type", reqContent, - "resp_content_length", writer.bytesWritten, - "resp_content_type", respContent, - "remote_addr", remoteAddr, - "user_agent", userAgent, - "query", r.URL.RawQuery) + return ip, port } type responseWriter struct { diff --git a/internal/server/logging_middleware_test.go b/internal/server/logging_middleware_test.go index ce1e3ca..6a34b26 100644 --- a/internal/server/logging_middleware_test.go +++ b/internal/server/logging_middleware_test.go @@ -4,7 +4,6 @@ import ( "bytes" "encoding/json" "fmt" - "log/slog" "net/http" "net/http/httptest" "strings" @@ -16,44 +15,41 @@ import ( func TestMiddleware_LoggingMiddleware(t *testing.T) { out := &strings.Builder{} - logger := slog.New(slog.NewJSONHandler(out, nil)) - middleware := NewLoggingMiddleware(logger, http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + middleware := NewLoggingMiddleware(out, http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.Header().Set("Content-Type", "text/html") w.WriteHeader(http.StatusCreated) fmt.Fprintln(w, "goodbye") })) - req := httptest.NewRequest("POST", "/somepath?q=ok", bytes.NewReader([]byte("hello"))) - req.Header.Set("X-Forwarded-For", "192.168.1.1") + req := httptest.NewRequest("POST", "http://example.com/somepath?q=ok", bytes.NewReader([]byte("hello"))) + req.Header.Set("X-Forwarded-For", "192.168.1.1, 10.1.1.1") req.Header.Set("User-Agent", "Robot/1") req.Header.Set("Content-Type", "application/json") middleware.ServeHTTP(httptest.NewRecorder(), req) - logline := struct { - Path string `json:"path"` - Method string `json:"method"` - Status int `json:"status"` - RemoteAddr string `json:"remote_addr"` - UserAgent string `json:"user_agent"` - ReqContentLength int64 `json:"req_content_length"` - ReqContentType string `json:"req_content_type"` - RespContentLength int64 `json:"resp_content_length"` - RespContentType string `json:"resp_content_type"` - Query string `json:"query"` - }{} + var logline LoggingMiddlewareLine err := json.NewDecoder(strings.NewReader(out.String())).Decode(&logline) require.NoError(t, err) - assert.Equal(t, "/somepath", logline.Path) - assert.Equal(t, "POST", logline.Method) - assert.Equal(t, http.StatusCreated, logline.Status) - assert.Equal(t, "192.168.1.1", logline.RemoteAddr) - assert.Equal(t, "Robot/1", logline.UserAgent) - assert.Equal(t, "application/json", logline.ReqContentType) - assert.Equal(t, "text/html", logline.RespContentType) - assert.Equal(t, "q=ok", logline.Query) - assert.Equal(t, int64(5), logline.ReqContentLength) - assert.Equal(t, int64(8), logline.RespContentLength) + assert.Equal(t, "Request", logline.Message) + assert.Equal(t, "INFO", logline.Log.Level) + + assert.Equal(t, "http", logline.URL.Scheme) + assert.Equal(t, "example.com", logline.URL.Domain) + assert.Equal(t, "/somepath", logline.URL.Path) + assert.Equal(t, "q=ok", logline.URL.Query) + assert.Equal(t, "Robot/1", logline.UserAgent.Original) + + assert.Equal(t, "192.168.1.1", logline.Client.IP) + assert.Equal(t, 1234, logline.Client.Port) + + assert.Equal(t, "POST", logline.HTTP.Request.Method) + assert.Equal(t, "application/json", logline.HTTP.Request.MimeType) + assert.Equal(t, int64(5), logline.HTTP.Request.Body.Bytes) + + assert.Equal(t, http.StatusCreated, logline.HTTP.Response.StatusCode) + assert.Equal(t, "text/html", logline.HTTP.Response.MimeType) + assert.Equal(t, int64(8), logline.HTTP.Response.Body.Bytes) } diff --git a/internal/server/server.go b/internal/server/server.go index 45fbeae..cb5ccc0 100644 --- a/internal/server/server.go +++ b/internal/server/server.go @@ -7,6 +7,7 @@ import ( "fmt" "log/slog" "net/http" + "os" "time" "golang.org/x/crypto/acme" @@ -85,5 +86,5 @@ func (s *Server) startCommandHandler() { } func (s *Server) buildHandler() http.Handler { - return NewLoggingMiddleware(slog.Default(), s.router) + return NewLoggingMiddleware(os.Stdout, s.router) }