Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Replace API Debug Middleware #631

Open
wants to merge 1 commit into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion internal/api/api.go
Original file line number Diff line number Diff line change
Expand Up @@ -90,7 +90,7 @@
handler = versionHeaderMiddleware(config.AppVersion)(handler)
if config.Debug {
handler = goahttpmwr.Log(loggerAdapter(logger))(handler)
handler = goahttpmwr.Debug(mux, os.Stdout)(handler)
handler = Debug(mux, os.Stdout)(handler)

Check warning on line 93 in internal/api/api.go

View check run for this annotation

Codecov / codecov/patch

internal/api/api.go#L93

Added line #L93 was not covered by tests
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is it possible to wrap goahttpmwr.Debug with an additional layer that checks the content type and conditionally intercepts the request? If the request content type indicates a large body, you could temporarily replace the body with an empty reader, allowing it to pass through the middleware without printing the full body. After the middleware processes the request, then reassign the original body for further processing. Not sure if that's possible but it seems doable.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

func conditionalDebug(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        if r.Header.Get("Content-Type") == "..." {
            originalBody := r.Body
            r.Body = io.NopCloser(io.LimitReader(originalBody, 0))
            next.ServeHTTP(w, r)
            r.Body = originalBody
        } else {
            next.ServeHTTP(w, r)
        }
    })
}

handler = conditionalDebug(goahttpmwr.Debug(mux, os.Stdout)(handler))

Copy link
Contributor Author

@DanielCosme DanielCosme Nov 13, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's really not that simple because this middleware:

  • Intercepts the (outgoing request), writes info to the buffer
  • calls next.ServeHTTP (in the middle of the function)
  • When the ServerHTTP returns then it works on the response.
  • Writes to the buffer the rest of the data (including the body)

And the Content-Type I check is the response one, not the request.

Copy link
Member

@sevein sevein Nov 14, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I see, sorry I missed that! Let me know if this other option works for you. This time, I used a different criteria: if the size of the debugging payload exceeds 16 KiB, then dump it into a file instead - but you could tweak the criterion as needed.

// middleware.go

// debugMiddleware is a wrapper around goahttpmwr.Debug that logs the output to
// a temporary file if it exceeds maxSize.
func debugMiddleware(mux goahttp.Muxer, w io.Writer) func(http.Handler) http.Handler {
	const maxSize = 16 * 1024
	return func(h http.Handler) http.Handler {
		return http.HandlerFunc(func(wr http.ResponseWriter, r *http.Request) {
			buf := &bytes.Buffer{}
			goahttpmwr.Debug(mux, buf)(h).ServeHTTP(wr, r)
			if buf.Len() < maxSize {
				io.Copy(w, buf)
			} else {
				tmpfile := "/tmp/debug.12345.log" // TODO: write to a temporary file.
				io.WriteString(w, fmt.Sprintf("\n [!] Response too large to be logged. Writing to %q.\n", tmpfile))
			}
		})
	}
}

Tests: https://go.dev/play/p/N8QDLTkZbBA.

I'd prefer a solution that doesn't require us to vendor all that code if possible.

Copy link
Contributor Author

@DanielCosme DanielCosme Nov 15, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This solution is better but it still does not fit the optimal solution for the client. Fundamentally the client wants be able to Debug the API when invoking the Download package endpoint, and by Debug we mean to be able to show request/response headers, params, status, etc.. without printing the response body (because it's a binary blob, we don't care about that).

Something like this would be the expected output in stdout:

> [VVbQVl5C] GET /collection/3/download
> [VVbQVl5C] Accept: */*
> [VVbQVl5C] User-Agent: curl/8.10.1
< [VVbQVl5C] OK
< [VVbQVl5C] Content-Disposition: attachment; filename="transfer_2_1.zip-830237d2-d82b-4943-b561-7fccac2ada1f.7z"
< [VVbQVl5C] Content-Length: 200895757
< [VVbQVl5C] Content-Type: application/x-7z-compressed
< [VVbQVl5C] X-Enduro-Version: (dev-version)

Note that we print all information, skipping only the body being printed (but successfully downloaded).

Your current proposal will either print all the Debug information (including the body) or nothing at all. Basically the io.Writer that the middleware takes will write everything. That is why I decided to fork/vendor this specific middleware, I could not see how to achieve the objective without that approach.

}

return &http.Server{
Expand Down
140 changes: 140 additions & 0 deletions internal/api/debug_middleware.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,140 @@
package api

import (
"bufio"
"bytes"
"crypto/rand"
"encoding/base64"
"fmt"
"io"
"net"
"net/http"
"sort"
"strings"

goahttp "goa.design/goa/v3/http"
"goa.design/goa/v3/middleware"
)

// Debug returns a debug middleware which prints detailed information about
// incoming requests and outgoing responses including all headers, parameters
// and bodies.
func Debug(mux goahttp.Muxer, w io.Writer) func(http.Handler) http.Handler {
return func(h http.Handler) http.Handler {
return http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) {
buf := &bytes.Buffer{}
// Request ID
reqID := r.Context().Value(middleware.RequestIDKey)
if reqID == nil {
reqID = shortID()
}

Check warning on line 30 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L22-L30

Added lines #L22 - L30 were not covered by tests

// Request URL
buf.WriteString(fmt.Sprintf("> [%s] %s %s", reqID, r.Method, r.URL.String()))

// Request Headers
keys := make([]string, len(r.Header))
i := 0
for k := range r.Header {
keys[i] = k
i++
}
sort.Strings(keys)
for _, k := range keys {
buf.WriteString(fmt.Sprintf("\n> [%s] %s: %s", reqID, k, strings.Join(r.Header[k], ", ")))
}

Check warning on line 45 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L33-L45

Added lines #L33 - L45 were not covered by tests

// Request parameters
params := mux.Vars(r)
keys = make([]string, len(params))
i = 0
for k := range params {
keys[i] = k
i++
}
sort.Strings(keys)
for _, k := range keys {
buf.WriteString(fmt.Sprintf("\n> [%s] %s: %s", reqID, k, params[k]))
}

Check warning on line 58 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L48-L58

Added lines #L48 - L58 were not covered by tests

// Request body
b, err := io.ReadAll(r.Body)
if err != nil {
b = []byte("failed to read body: " + err.Error())
}
if len(b) > 0 {
buf.WriteByte('\n')
lines := strings.Split(string(b), "\n")
for _, line := range lines {
buf.WriteString(fmt.Sprintf("[%s] %s\n", reqID, line))
}

Check warning on line 70 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L61-L70

Added lines #L61 - L70 were not covered by tests
}
r.Body = io.NopCloser(bytes.NewBuffer(b))

dupper := &responseDupper{ResponseWriter: rw, Buffer: &bytes.Buffer{}}
h.ServeHTTP(dupper, r)

buf.WriteString(fmt.Sprintf("\n< [%s] %s", reqID, http.StatusText(dupper.Status)))
keys = make([]string, len(dupper.Header()))
printResponseBody := true
i = 0
for k, v := range dupper.Header() {
if k == "Content-Type" && len(v) > 0 && v[0] == "application/x-7z-compressed" {
printResponseBody = false
}
keys[i] = k
i++

Check warning on line 86 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L72-L86

Added lines #L72 - L86 were not covered by tests
}
sort.Strings(keys)
for _, k := range keys {
buf.WriteString(fmt.Sprintf("\n< [%s] %s: %s", reqID, k, strings.Join(dupper.Header()[k], ", ")))
}
if printResponseBody {
buf.WriteByte('\n')
lines := strings.Split(dupper.Buffer.String(), "\n")
for _, line := range lines {
buf.WriteString(fmt.Sprintf("[%s] %s\n", reqID, line))
}

Check warning on line 97 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L88-L97

Added lines #L88 - L97 were not covered by tests
}
buf.WriteByte('\n')
_, err = w.Write(buf.Bytes()) // nolint: errcheck
if err != nil {
panic(err)

Check warning on line 102 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L99-L102

Added lines #L99 - L102 were not covered by tests
}
})
}
}

// responseDupper tees the response to a buffer and a response writer.
type responseDupper struct {
http.ResponseWriter
Buffer *bytes.Buffer
Status int
}

// Write writes the data to the buffer and connection as part of an HTTP reply.
func (r *responseDupper) Write(b []byte) (int, error) {
return io.MultiWriter(r.ResponseWriter, r.Buffer).Write(b)

Check warning on line 117 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L116-L117

Added lines #L116 - L117 were not covered by tests
}

// WriteHeader records the status and sends an HTTP response header with status code.
func (r *responseDupper) WriteHeader(s int) {
r.Status = s
r.ResponseWriter.WriteHeader(s)

Check warning on line 123 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L121-L123

Added lines #L121 - L123 were not covered by tests
}

// Hijack supports the http.Hijacker interface.
func (r *responseDupper) Hijack() (net.Conn, *bufio.ReadWriter, error) {
if hijacker, ok := r.ResponseWriter.(http.Hijacker); ok {
return hijacker.Hijack()
}
return nil, nil, fmt.Errorf("debug middleware: inner ResponseWriter cannot be hijacked: %T", r.ResponseWriter)

Check warning on line 131 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L127-L131

Added lines #L127 - L131 were not covered by tests
}

// shortID produces a " unique" 6 bytes long string.
// Do not use as a reliable way to get unique IDs, instead use for things like logging.
func shortID() string {
b := make([]byte, 6)
io.ReadFull(rand.Reader, b) // nolint: errcheck
return base64.RawURLEncoding.EncodeToString(b)

Check warning on line 139 in internal/api/debug_middleware.go

View check run for this annotation

Codecov / codecov/patch

internal/api/debug_middleware.go#L136-L139

Added lines #L136 - L139 were not covered by tests
}
Loading