diff --git a/.github/workflows/go.yml b/.github/workflows/go.yml index 7ae46a8..e2c29af 100644 --- a/.github/workflows/go.yml +++ b/.github/workflows/go.yml @@ -16,7 +16,7 @@ jobs: - name: Set up Go uses: actions/setup-go@v3 with: - go-version: 1.19.1 + go-version: 1.24.3 - name: Get coverage tool run: | diff --git a/Dockerfile b/Dockerfile index c5887cc..ddb3222 100644 --- a/Dockerfile +++ b/Dockerfile @@ -1,4 +1,4 @@ -FROM golang:1.18.2-alpine3.16 as builder +FROM golang:1.24-alpine3.21 AS builder WORKDIR /code/ @@ -6,7 +6,8 @@ ADD src/ . RUN go build -o dist/ -ldflags "-s -w" -FROM alpine:3.16 +FROM alpine:3.21 + WORKDIR /code/ COPY docker-entrypoint.sh /bin/ @@ -15,4 +16,4 @@ ENTRYPOINT ["/bin/docker-entrypoint.sh"] COPY --from=builder /code/dist/go-http-server /bin/ RUN chmod +x /bin/go-http-server -CMD "/bin/go-http-server" \ No newline at end of file +CMD ["/bin/go-http-server"] diff --git a/src/go.mod b/src/go.mod index d6e6c8d..d3ebb6b 100644 --- a/src/go.mod +++ b/src/go.mod @@ -1,22 +1,18 @@ module go-http-server -go 1.18 +go 1.24.3 require ( bou.ke/monkey v1.0.2 github.com/andybalholm/brotli v1.0.4 github.com/felixge/httpsnoop v1.0.3 github.com/hashicorp/golang-lru v0.5.4 - github.com/rs/zerolog v1.29.1 github.com/urfave/cli/v2 v2.16.3 golang.org/x/exp v0.0.0-20220518171630-0b5c67f07fdf ) require ( github.com/cpuguy83/go-md2man/v2 v2.0.2 // indirect - github.com/mattn/go-colorable v0.1.13 // indirect - github.com/mattn/go-isatty v0.0.19 // indirect github.com/russross/blackfriday/v2 v2.1.0 // indirect github.com/xrash/smetrics v0.0.0-20201216005158-039620a65673 // indirect - golang.org/x/sys v0.10.0 // indirect ) diff --git a/src/go.sum b/src/go.sum index 257872c..8e9adcc 100644 --- a/src/go.sum +++ b/src/go.sum @@ -2,25 +2,12 @@ bou.ke/monkey v1.0.2 h1:kWcnsrCNUatbxncxR/ThdYqbytgOIArtYWqcQLQzKLI= bou.ke/monkey v1.0.2/go.mod h1:OqickVX3tNx6t33n1xvtTtu85YN5s6cKwVug+oHMaIA= github.com/andybalholm/brotli v1.0.4 h1:V7DdXeJtZscaqfNuAdSRuRFzuiKlHSC/Zh3zl9qY3JY= github.com/andybalholm/brotli v1.0.4/go.mod h1:fO7iG3H7G2nSZ7m0zPUDn85XEX2GTukHGRSepvi9Eig= -github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/cpuguy83/go-md2man/v2 v2.0.2 h1:p1EgwI/C7NhT0JmVkwCD2ZBK8j4aeHQX2pMHHBfMQ6w= github.com/cpuguy83/go-md2man/v2 v2.0.2/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o= github.com/felixge/httpsnoop v1.0.3 h1:s/nj+GCswXYzN5v2DpNMuMQYe+0DDwt5WVCU6CWBdXk= github.com/felixge/httpsnoop v1.0.3/go.mod h1:m8KPJKqk1gH5J9DgRY2ASl2lWCfGKXixSwevea8zH2U= -github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= github.com/hashicorp/golang-lru v0.5.4 h1:YDjusn29QI/Das2iO9M0BHnIbxPeyuCHsjMW+lJfyTc= github.com/hashicorp/golang-lru v0.5.4/go.mod h1:iADmTwqILo4mZ8BN3D2Q6+9jd8WM5uGBxy+E8yxSoD4= -github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= -github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA= -github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg= -github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= -github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= -github.com/mattn/go-isatty v0.0.19 h1:JITubQf0MOLdlGRuRq+jtsDlekdYPia9ZFsB8h/APPA= -github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= -github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= -github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= -github.com/rs/zerolog v1.29.1 h1:cO+d60CHkknCbvzEWxP0S9K6KqyTjrCNUy1LdQLCGPc= -github.com/rs/zerolog v1.29.1/go.mod h1:Le6ESbR7hc+DP6Lt1THiV8CQSdkkNrd3R0XbEgp3ZBU= github.com/russross/blackfriday/v2 v2.1.0 h1:JIOH55/0cWyOuilr9/qlrm0BSXldqnqwMsf35Ld67mk= github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= github.com/urfave/cli/v2 v2.16.3 h1:gHoFIwpPjoyIMbJp/VFd+/vuD0dAgFK4B6DpEMFJfQk= @@ -29,9 +16,3 @@ github.com/xrash/smetrics v0.0.0-20201216005158-039620a65673 h1:bAn7/zixMGCfxrRT github.com/xrash/smetrics v0.0.0-20201216005158-039620a65673/go.mod h1:N3UwUGtsrSj3ccvlPHLoLsHnpR27oXr4ZE984MbSER8= golang.org/x/exp v0.0.0-20220518171630-0b5c67f07fdf h1:oXVg4h2qJDd9htKxb5SCpFBHLipW6hXmL3qpUixS2jw= golang.org/x/exp v0.0.0-20220518171630-0b5c67f07fdf/go.mod h1:yh0Ynu2b5ZUe3MQfp2nM0ecK7wsgouWTDN0FNeJuIys= -golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.10.0 h1:SqMFp9UcQJZa+pmYuAKjd9xq1f0j5rLcDIk0mj4qAsA= -golang.org/x/sys v0.10.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= diff --git a/src/util/log.go b/src/util/log.go index 8a633f8..3139ba2 100644 --- a/src/util/log.go +++ b/src/util/log.go @@ -1,14 +1,13 @@ package util import ( + "log/slog" "net" "net/http" "os" "time" "github.com/felixge/httpsnoop" - "github.com/rs/zerolog" - "github.com/rs/zerolog/log" ) type LogRequestHandlerOptions struct { @@ -35,31 +34,32 @@ type HTTPReqInfo struct { referer string } -func logHTTPReqInfo(ri *HTTPReqInfo) { - log.Info(). - Str("method", ri.method). - Str("path", ri.path). - Int("code", ri.code). - Int64("size", ri.size). - Dur("duration", ri.duration). - IPAddr("ipAddress", ri.ipAddress). - Str("userAgent", ri.userAgent). - Str("referer", ri.referer). - Send() +func logHTTPReqInfo(l *slog.Logger, ri *HTTPReqInfo) { + l.Info("HTTP Request", + "method", ri.method, + "path", ri.path, + slog.Int("code", ri.code), + slog.Int64("size", ri.size), + slog.Int64("duration", ri.duration.Milliseconds()), // in milliseconds + "ipAddress", ri.ipAddress, + "userAgent", ri.userAgent, + "referer", ri.referer, + ) } func LogRequestHandler(h http.Handler, opt *LogRequestHandlerOptions) http.Handler { + var logger *slog.Logger if opt.Pretty { - log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr}) + logger = slog.New(slog.NewTextHandler(os.Stdout, nil)) + } else { + logger = slog.New(slog.NewJSONHandler(os.Stdout, nil)) } - zerolog.DurationFieldUnit = time.Millisecond - fn := func(w http.ResponseWriter, r *http.Request) { // runs handler h and captures information about HTTP request mtr := httpsnoop.CaptureMetrics(h, w, r) - logHTTPReqInfo(&HTTPReqInfo{ + logHTTPReqInfo(logger, &HTTPReqInfo{ method: r.Method, path: r.URL.String(), code: mtr.Code, diff --git a/src/util/log_test.go b/src/util/log_test.go new file mode 100644 index 0000000..e13982d --- /dev/null +++ b/src/util/log_test.go @@ -0,0 +1,392 @@ +package util + +import ( + "bytes" + "encoding/json" + "log/slog" + "net" + "net/http" + "net/http/httptest" + "strings" + "testing" + "time" + + "github.com/felixge/httpsnoop" +) + +func TestLogHTTPReqInfo(t *testing.T) { + var buf bytes.Buffer + logger := slog.New(slog.NewJSONHandler(&buf, nil)) + + ri := &HTTPReqInfo{ + method: "GET", + path: "/test/path", + code: 200, + size: 1234, + duration: 150 * time.Millisecond, + ipAddress: net.ParseIP("127.0.0.1"), + userAgent: "Go-http-client/1.1", + referer: "http://example.com", + } + + logHTTPReqInfo(logger, ri) + + logged := buf.String() + + // Parse the JSON log entry + var logData map[string]interface{} + if err := json.Unmarshal([]byte(logged), &logData); err != nil { + t.Fatalf("Failed to parse log output as JSON: %v\nLog output: %s", err, logged) + } + + tests := []struct { + field string + want interface{} + }{ + {"method", "GET"}, + {"path", "/test/path"}, + {"code", float64(200)}, // JSON numbers are float64 + {"size", float64(1234)}, + {"ipAddress", "127.0.0.1"}, + {"userAgent", "Go-http-client/1.1"}, + {"referer", "http://example.com"}, + } + + for _, tt := range tests { + if value, ok := logData[tt.field]; !ok { + t.Errorf("Expected log to contain field %q, got: %s", tt.field, logged) + } else if value != tt.want { + t.Errorf("Expected field %q to be %v, got %v", tt.field, tt.want, value) + } + } + + // Check that duration field exists and is a number (slog duration format in nanoseconds) + if duration, ok := logData["duration"]; !ok { + t.Errorf("Expected log to contain 'duration' field, got: %s", logged) + } else if _, ok := duration.(float64); !ok { + t.Errorf("Expected duration to be a number, got %T: %v", duration, duration) + } + + // Check that msg field exists + if msg, ok := logData["msg"]; !ok { + t.Errorf("Expected log to contain 'msg' field, got: %s", logged) + } else if msg != "HTTP Request" { + t.Errorf("Expected msg to be 'HTTP Request', got %v", msg) + } +} + +func TestLogRequestHandler(t *testing.T) { + tests := []struct { + name string + pretty bool + method string + path string + userAgent string + referer string + remoteAddr string + wantMethod string + wantPath string + wantAgent string + wantReferer string + }{ + { + name: "GET request with all headers", + pretty: false, + method: "GET", + path: "/api/test", + userAgent: "Mozilla/5.0", + referer: "https://example.com", + remoteAddr: "192.168.1.1:12345", + wantMethod: "GET", + wantPath: "/api/test", + wantAgent: "Mozilla/5.0", + wantReferer: "https://example.com", + }, + { + name: "POST request without headers", + pretty: false, + method: "POST", + path: "/api/submit", + userAgent: "", + referer: "", + remoteAddr: "127.0.0.1:8080", + wantMethod: "POST", + wantPath: "/api/submit", + wantAgent: "", + wantReferer: "", + }, + { + name: "PUT request with query parameters", + pretty: false, + method: "PUT", + path: "/api/update?id=123¶m=value", + userAgent: "Go-http-client/1.1", + referer: "http://localhost:3000", + remoteAddr: "10.0.0.1:54321", + wantMethod: "PUT", + wantPath: "/api/update?id=123¶m=value", + wantAgent: "Go-http-client/1.1", + wantReferer: "http://localhost:3000", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + // Capture log output to a buffer instead of stdout + var buf bytes.Buffer + + // Create the logging handler with a custom logger that writes to our buffer + dummyHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + w.Write([]byte("test response")) + }) + + // Create a custom version of LogRequestHandler that uses our buffer for logging + var logger *slog.Logger + if tt.pretty { + logger = slog.New(slog.NewTextHandler(&buf, nil)) + } else { + logger = slog.New(slog.NewJSONHandler(&buf, nil)) + } + + // Create a modified version of LogRequestHandler that uses our logger + fn := func(w http.ResponseWriter, r *http.Request) { + // runs handler and captures information about HTTP request + mtr := httpsnoop.CaptureMetrics(dummyHandler, w, r) + + logHTTPReqInfo(logger, &HTTPReqInfo{ + method: r.Method, + path: r.URL.String(), + code: mtr.Code, + size: mtr.Written, + duration: mtr.Duration, + ipAddress: requestGetRemoteAddress(r), + userAgent: r.Header.Get("User-Agent"), + referer: r.Header.Get("Referer"), + }) + } + handler := http.HandlerFunc(fn) + + // Create test request + req := httptest.NewRequest(tt.method, tt.path, nil) + req.RemoteAddr = tt.remoteAddr + if tt.userAgent != "" { + req.Header.Set("User-Agent", tt.userAgent) + } + if tt.referer != "" { + req.Header.Set("Referer", tt.referer) + } + + // Create response recorder + w := httptest.NewRecorder() + + // Execute the handler + handler.ServeHTTP(w, req) + + // Verify the response + if w.Code != http.StatusOK { + t.Errorf("Expected status %d, got %d", http.StatusOK, w.Code) + } + + if w.Body.String() != "test response" { + t.Errorf("Expected body 'test response', got '%s'", w.Body.String()) + } + + // Verify the log output + logged := buf.String() + + // Basic check that we got some log output + if len(logged) == 0 { + t.Errorf("Expected log output, got empty string") + return + } + + if !tt.pretty { + // For JSON format, parse and validate the structure + var logData map[string]interface{} + if err := json.Unmarshal([]byte(logged), &logData); err != nil { + t.Errorf("Failed to parse log output as JSON: %v\nLog output: %s", err, logged) + return + } + + // Check required fields + if method, ok := logData["method"]; !ok || method != tt.wantMethod { + t.Errorf("Expected method %q, got %v", tt.wantMethod, method) + } + if path, ok := logData["path"]; !ok || path != tt.wantPath { + t.Errorf("Expected path %q, got %v", tt.wantPath, path) + } + if code, ok := logData["code"]; !ok || code != float64(200) { + t.Errorf("Expected code 200, got %v", code) + } + if size, ok := logData["size"]; !ok || size != float64(13) { // "test response" is 13 bytes + t.Errorf("Expected size 13, got %v", size) + } + + // Check optional header fields only if they should be present + if tt.wantAgent != "" { + if userAgent, ok := logData["userAgent"]; !ok || userAgent != tt.wantAgent { + t.Errorf("Expected userAgent %q, got %v", tt.wantAgent, userAgent) + } + } + if tt.wantReferer != "" { + if referer, ok := logData["referer"]; !ok || referer != tt.wantReferer { + t.Errorf("Expected referer %q, got %v", tt.wantReferer, referer) + } + } + + // Verify duration and ipAddress fields exist + if _, ok := logData["duration"]; !ok { + t.Errorf("Expected log to contain 'duration' field, got: %s", logged) + } + if _, ok := logData["ipAddress"]; !ok { + t.Errorf("Expected log to contain 'ipAddress' field, got: %s", logged) + } + } else { + // For pretty format, just check that key information is present + if !strings.Contains(logged, tt.wantMethod) { + t.Errorf("Expected log to contain method %q, got: %s", tt.wantMethod, logged) + } + if !strings.Contains(logged, tt.wantPath) { + t.Errorf("Expected log to contain path %q, got: %s", tt.wantPath, logged) + } + } + }) + } +} + +func TestLogRequestHandlerWithDifferentStatusCodes(t *testing.T) { + tests := []struct { + name string + statusCode int + response string + }{ + {"Not Found", http.StatusNotFound, "not found"}, + {"Internal Server Error", http.StatusInternalServerError, "error occurred"}, + {"Created", http.StatusCreated, "resource created"}, + {"No Content", http.StatusNoContent, ""}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + // Capture log output + var buf bytes.Buffer + logger := slog.New(slog.NewJSONHandler(&buf, nil)) + + // Create a dummy handler that returns the specified status code + dummyHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(tt.statusCode) + if tt.response != "" { + w.Write([]byte(tt.response)) + } + }) + + // Create a custom handler that uses our logger + fn := func(w http.ResponseWriter, r *http.Request) { + mtr := httpsnoop.CaptureMetrics(dummyHandler, w, r) + + logHTTPReqInfo(logger, &HTTPReqInfo{ + method: r.Method, + path: r.URL.String(), + code: mtr.Code, + size: mtr.Written, + duration: mtr.Duration, + ipAddress: requestGetRemoteAddress(r), + userAgent: r.Header.Get("User-Agent"), + referer: r.Header.Get("Referer"), + }) + } + handler := http.HandlerFunc(fn) + + // Create test request + req := httptest.NewRequest("GET", "/test", nil) + req.RemoteAddr = "127.0.0.1:12345" + + // Create response recorder + w := httptest.NewRecorder() + + // Execute the handler + handler.ServeHTTP(w, req) + + // Verify the response + if w.Code != tt.statusCode { + t.Errorf("Expected status %d, got %d", tt.statusCode, w.Code) + } + + // Verify the log contains the correct status code + logged := buf.String() + + var logData map[string]interface{} + if err := json.Unmarshal([]byte(logged), &logData); err != nil { + t.Errorf("Failed to parse log output as JSON: %v", err) + return + } + + if code, ok := logData["code"]; !ok || code != float64(tt.statusCode) { + t.Errorf("Expected code %d, got %v", tt.statusCode, code) + } + + // Verify expected response size + expectedSize := int64(len(tt.response)) + if size, ok := logData["size"]; !ok || size != float64(expectedSize) { + t.Errorf("Expected size %d, got %v", expectedSize, size) + } + }) + } +} + +func TestLogRequestHandlerPrettyLogging(t *testing.T) { + // Test that the pretty option works without errors + var buf bytes.Buffer + logger := slog.New(slog.NewTextHandler(&buf, nil)) + + dummyHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + w.Write([]byte("ok")) + }) + + // Create a custom handler with pretty logging + fn := func(w http.ResponseWriter, r *http.Request) { + mtr := httpsnoop.CaptureMetrics(dummyHandler, w, r) + + logHTTPReqInfo(logger, &HTTPReqInfo{ + method: r.Method, + path: r.URL.String(), + code: mtr.Code, + size: mtr.Written, + duration: mtr.Duration, + ipAddress: requestGetRemoteAddress(r), + userAgent: r.Header.Get("User-Agent"), + referer: r.Header.Get("Referer"), + }) + } + handler := http.HandlerFunc(fn) + + req := httptest.NewRequest("GET", "/", nil) + req.RemoteAddr = "127.0.0.1:8080" + w := httptest.NewRecorder() + + handler.ServeHTTP(w, req) + + // Verify the handler still works correctly + if w.Code != http.StatusOK { + t.Errorf("Expected status 200, got %d", w.Code) + } + if w.Body.String() != "ok" { + t.Errorf("Expected body 'ok', got '%s'", w.Body.String()) + } + + // Verify that we got some log output (text format) + logged := buf.String() + if len(logged) == 0 { + t.Errorf("Expected log output, got empty string") + } + + // For text format, just verify key information is present + if !strings.Contains(logged, "GET") { + t.Errorf("Expected log to contain method 'GET', got: %s", logged) + } + if !strings.Contains(logged, "HTTP Request") { + t.Errorf("Expected log to contain message 'HTTP Request', got: %s", logged) + } +}