From 171330f9b6b239a8b170ebdf6bd1bf59cccb551c Mon Sep 17 00:00:00 2001 From: Vojtech Vitek Date: Fri, 4 Oct 2024 15:41:28 +0200 Subject: [PATCH 1/4] Implement transport.LogRequests() - Remove external dependencies (implement our own CURL printer) - Switch to slog.Logger (requires Go 1.21) - Require new opts param (this is technically breaking change, but we're under v0.0.0-, so it's fine). --- curl.go | 42 +++++++++++++++++++++++++++++++ go.mod | 2 -- go.sum | 33 ------------------------ logRequests.go | 68 +++++++++++++++++++++++++++++++++++++------------- 4 files changed, 93 insertions(+), 52 deletions(-) create mode 100644 curl.go diff --git a/curl.go b/curl.go new file mode 100644 index 0000000..9ca30de --- /dev/null +++ b/curl.go @@ -0,0 +1,42 @@ +package transport + +import ( + "bytes" + "fmt" + "net/http" + "strings" +) + +func curl(r *http.Request, body *bytes.Buffer) string { + var b strings.Builder + + fmt.Fprintf(&b, "curl") + if r.Method != "GET" && r.Method != "POST" { + fmt.Fprintf(&b, " -X %s", r.Method) + } + + fmt.Fprintf(&b, " %s", singleQuoted(r.URL.String())) + + if r.Method == "POST" { + fmt.Fprintf(&b, " --data-raw %s", singleQuoted(body.String())) + } + + for name, vals := range r.Header { + for _, val := range vals { + fmt.Fprintf(&b, " -H %s", singleQuoted(fmt.Sprintf("%s: %s", name, val))) + } + } + + return b.String() +} + +func scheme(r *http.Request) string { + if r.TLS != nil { + return "https" + } + return "http" +} + +func singleQuoted(v string) string { + return fmt.Sprintf("'%s'", strings.ReplaceAll(v, "'", `'\''`)) +} diff --git a/go.mod b/go.mod index 2fa72c7..df3c679 100644 --- a/go.mod +++ b/go.mod @@ -2,6 +2,4 @@ module github.com/go-chi/transport go 1.14 -require moul.io/http2curl/v2 v2.3.0 - require golang.org/x/sync v0.4.0 diff --git a/go.sum b/go.sum index a3ec3aa..6a07ba6 100644 --- a/go.sum +++ b/go.sum @@ -1,35 +1,2 @@ -github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= -github.com/pkg/diff v0.0.0-20200914180035-5b29258ca4f7/go.mod h1:zO8QMzTeZd5cpnIkz/Gn6iK0jDfGicM1nynOkkPIl28= -github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= -github.com/sergi/go-diff v1.0.0/go.mod h1:0CfEIISq7TuYL3j771MWULgwwjU+GofnZX9QAmXWZgo= -github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= -github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= -github.com/tailscale/depaware v0.0.0-20210622194025-720c4b409502/go.mod h1:p9lPsd+cx33L3H9nNoecRRxPssFKUwwI50I3pZ0yT+8= -github.com/yuin/goldmark v1.2.1/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= -golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= -golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= -golang.org/x/crypto v0.0.0-20200622213623-75b288015ac9/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto= -golang.org/x/mod v0.3.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= -golang.org/x/mod v0.4.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= -golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= -golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s= -golang.org/x/net v0.0.0-20201021035429-f5854403a974/go.mod h1:sp8m0HH+o8qH0wwXwYZr8TS3Oi6o0r6Gce1SSxlDquU= -golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= -golang.org/x/sync v0.0.0-20201020160332-67f06af15bc9/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.4.0 h1:zxkM55ReGkDlKSM+Fu41A+zmbZuaPVbGMzvvdUPznYQ= golang.org/x/sync v0.4.0/go.mod h1:FU7BRWz2tNW+3quACPkgCx/L+uEAv1htQ0V83Z9Rj+Y= -golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= -golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= -golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= -golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= -golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= -golang.org/x/tools v0.0.0-20201211185031-d93e913c1a58/go.mod h1:emZCQorbCU4vsT4fOWvOPXz4eW1wZW4PmDk9uLelYpA= -golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= -golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= -golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= -gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= -gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= -moul.io/http2curl/v2 v2.3.0 h1:9r3JfDzWPcbIklMOs2TnIFzDYvfAZvjeavG6EzP7jYs= -moul.io/http2curl/v2 v2.3.0/go.mod h1:RW4hyBjTWSYDOxapodpNEtX0g5Eb16sxklBqmd2RHcE= diff --git a/logRequests.go b/logRequests.go index ac0e847..f37f03d 100644 --- a/logRequests.go +++ b/logRequests.go @@ -1,30 +1,64 @@ +//go:build go1.21 + package transport import ( - "log" + "bytes" + "fmt" + "io" "net/http" "time" - "moul.io/http2curl/v2" + "log/slog" ) -func LogRequests(next http.RoundTripper) http.RoundTripper { - return RoundTripFunc(func(req *http.Request) (resp *http.Response, err error) { - r := CloneRequest(req) +type LogOptions struct { + Concise bool + CURL bool +} - curlCommand, _ := http2curl.GetCurlCommand(r) - log.Printf("%v", curlCommand) - log.Printf("request: %s %s", r.Method, r.URL) +func LogRequests(opts LogOptions) func(next http.RoundTripper) http.RoundTripper { + return func(next http.RoundTripper) http.RoundTripper { + return RoundTripFunc(func(req *http.Request) (resp *http.Response, err error) { + ctx := req.Context() + r := CloneRequest(req) - startTime := time.Now() - defer func() { - if resp != nil { - log.Printf("response (HTTP %v): %v %s", time.Since(startTime), resp.Status, r.URL) - } else { - log.Printf("response (): %v %s", time.Since(startTime), r.URL) + var buf bytes.Buffer + if opts.CURL && r.Body != nil { + r.Body = io.NopCloser(io.TeeReader(r.Body, &buf)) } - }() - return next.RoundTrip(r) - }) + slog.LogAttrs(ctx, slog.LevelDebug, fmt.Sprintf("Request: %v %s", r.Method, r.URL.String())) + + startTime := time.Now() + defer func() { + level := slog.LevelError + var statusCode int + if resp != nil { + statusCode = resp.StatusCode + if statusCode >= 200 && statusCode < 400 { + level = slog.LevelInfo + } + } + + attrs := []slog.Attr{} + if opts.CURL { + attrs = append(attrs, slog.String("curl", curl(r, &buf))) + } + + if opts.Concise { + slog.LogAttrs(ctx, level, fmt.Sprintf("Request: %v %s => HTTP %v (%v)", r.Method, r.URL.String(), statusCode, time.Since(startTime)), attrs...) + } else { + attrs = append(attrs, + slog.String("url", r.URL.String()), + slog.Duration("duration", time.Since(startTime)), + slog.Int("status", statusCode), + ) + slog.LogAttrs(ctx, level, fmt.Sprintf("Request"), attrs...) + } + }() + + return next.RoundTrip(r) + }) + } } From 2cb71e32cf0107aaeb4f6db6c1e1306461ef9e99 Mon Sep 17 00:00:00 2001 From: Vojtech Vitek Date: Fri, 4 Oct 2024 16:03:19 +0200 Subject: [PATCH 2/4] Fix tests --- setHeaderFunc_test.go | 2 +- setHeader_test.go | 2 +- transport_test.go | 27 +++++++++++++++++---------- 3 files changed, 19 insertions(+), 12 deletions(-) diff --git a/setHeaderFunc_test.go b/setHeaderFunc_test.go index bf48d02..31eb290 100644 --- a/setHeaderFunc_test.go +++ b/setHeaderFunc_test.go @@ -34,7 +34,7 @@ func TestSetHeaderFunc(t *testing.T) { Transport: transport.Chain( http.DefaultTransport, transport.SetHeaderFunc("Authorization", issueRandomAuthToken), - transport.LogRequests, + transport.LogRequests(transport.LogOptions{}), ), Timeout: 15 * time.Second, } diff --git a/setHeader_test.go b/setHeader_test.go index 8ea71bf..e831f88 100644 --- a/setHeader_test.go +++ b/setHeader_test.go @@ -45,7 +45,7 @@ func TestSetHeader(t *testing.T) { transport.SetHeader("User-Agent", userAgent), transport.SetHeader("Authorization", authHeader), transport.SetHeader("x-extra", "value"), - transport.LogRequests, + transport.LogRequests(transport.LogOptions{}), ), Timeout: 15 * time.Second, } diff --git a/transport_test.go b/transport_test.go index 748d319..1784ead 100644 --- a/transport_test.go +++ b/transport_test.go @@ -1,4 +1,4 @@ -package transport +package transport_test import ( "fmt" @@ -6,6 +6,8 @@ import ( "net/http/httptest" "testing" "time" + + "github.com/go-chi/transport" ) func TestChain(t *testing.T) { @@ -16,16 +18,21 @@ func TestChain(t *testing.T) { return } + if r.Header.Get("Accept-Encoding") != "gzip" { + w.WriteHeader(500) + return + } + fmt.Fprintf(w, expected) })) defer server.Close() client := &http.Client{ Timeout: 15 * time.Second, - Transport: Chain( + Transport: transport.Chain( nil, - SetHeader("User-Agent", "transport-chain/v1.0.0"), - LogRequests, + transport.SetHeader("User-Agent", "transport-chain/v1.0.0"), + transport.SetHeader("Accept-Encoding", "gzip"), ), } @@ -61,10 +68,10 @@ func TestChainWithRetries(t *testing.T) { client := &http.Client{ Timeout: 15 * time.Second, - Transport: Chain( + Transport: transport.Chain( http.DefaultTransport, - Retry(http.DefaultTransport, 5), - LogRequests, + transport.Retry(http.DefaultTransport, 5), + transport.LogRequests(transport.LogOptions{}), ), } @@ -101,10 +108,10 @@ func TestChainWithRetryAfter(t *testing.T) { client := &http.Client{ Timeout: 15 * time.Second, - Transport: Chain( + Transport: transport.Chain( http.DefaultTransport, - Retry(http.DefaultTransport, 5), - LogRequests, + transport.Retry(http.DefaultTransport, 5), + transport.LogRequests(transport.LogOptions{}), ), } From 5fca50d08c11b4cb2dec9dc15812d5133f5e02e1 Mon Sep 17 00:00:00 2001 From: Vojtech Vitek Date: Fri, 4 Oct 2024 16:07:30 +0200 Subject: [PATCH 3/4] Update README --- README.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index 9b7d8b3..8942cdb 100644 --- a/README.md +++ b/README.md @@ -20,13 +20,13 @@ authClient := http.Client{ } ``` -Or debug all outgoing requests globally within your application: +Or debug all outgoing requests as `curl` globally within your application: ```go debugMode := os.Getenv("DEBUG") == "true" http.DefaultTransport = transport.Chain( http.DefaultTransport, - transport.If(debugMode, transport.LogRequests), + transport.If(debugMode, transport.LogRequests(transport.LogOptions{Concise: true, CURL: true})), ) ``` From 1a2ee44d8f3de4c1d450ab38d8fb572f4097aae8 Mon Sep 17 00:00:00 2001 From: Vojtech Vitek Date: Fri, 4 Oct 2024 16:14:55 +0200 Subject: [PATCH 4/4] Remove unused code; PR feedback --- curl.go | 7 ------- 1 file changed, 7 deletions(-) diff --git a/curl.go b/curl.go index 9ca30de..9bebf30 100644 --- a/curl.go +++ b/curl.go @@ -30,13 +30,6 @@ func curl(r *http.Request, body *bytes.Buffer) string { return b.String() } -func scheme(r *http.Request) string { - if r.TLS != nil { - return "https" - } - return "http" -} - func singleQuoted(v string) string { return fmt.Sprintf("'%s'", strings.ReplaceAll(v, "'", `'\''`)) }