diff --git a/e2e_known_issues_test.go b/e2e_known_issues_test.go index f75e253..749cef5 100644 --- a/e2e_known_issues_test.go +++ b/e2e_known_issues_test.go @@ -1,9 +1,6 @@ package main_test -import ( - "strings" - "testing" -) +import "testing" // This file pins behaviour that is currently WRONG. Each test asserts what the // tool does today and names the issue tracking the defect. @@ -46,25 +43,6 @@ func TestIssue17BadPatternIsRejected(t *testing.T) { }) } -// TestKnownIssue19RequestBodyMissing: the request is dumped after the transport -// has drained its body, so Content-Length advertises bytes that are not shown. -func TestKnownIssue19RequestBodyMissing(t *testing.T) { - characterizes(t, 19, "the request dump omits the -d payload it advertises") - - r := run(t, nil, "-X", "POST", "-d", "sent-but-not-shown", "--assert-status", "999", url("/echo")) - assertExit(t, r, exitRequestFail) - - // The echoed response proves the body reached the server... - assertContains(t, r, "sent-but-not-shown") - // ...while the request dump advertises its length and shows nothing. - assertContains(t, r, "Content-Length: 18") - - reqDump, _, _ := strings.Cut(r.Output(), "HTTP/1.1 200 OK") - if strings.Contains(reqDump, "sent-but-not-shown") { - t.Fatal("request dump now includes the body; #19 is fixed -- update this test") - } -} - // TestKnownIssue20AssertOkAcceptsRedirects: --assert-ok is documented as "2xx" // but implemented as 200-399. func TestKnownIssue20AssertOkAcceptsRedirects(t *testing.T) { diff --git a/main.go b/main.go index 3c63b64..e617b06 100644 --- a/main.go +++ b/main.go @@ -899,7 +899,7 @@ func (c Client) writeHttpDetails(w io.Writer, req *http.Request, res *httpRespon if res != nil && res.Request != nil && res.Request.URL.String() != req.URL.String() { _, _ = fmt.Fprintf(w, "Followed to: %s %s\n\n", res.Request.Method, res.Request.URL) } - _ = req.Write(w) + writeRequest(w, req) _, _ = w.Write([]byte("\n\n")) if res != nil { res.writeTo(w, c.LogLevel >= LInfo) @@ -907,6 +907,47 @@ func (c Client) writeHttpDetails(w io.Writer, req *http.Request, res *httpRespon } } +// writeRequest renders the request for a person reading a failure report, the +// way writeTo renders the response. +// +// http.Request.Write alone gets this wrong twice. Its body has already been +// consumed by the send, so it emits headers claiming a Content-Length with +// nothing behind them -- the first question after a failed POST is "what did I +// send?", and that was the one thing the dump left out (#19). And it is a +// wire-format serializer, so a long or binary payload would land in the report +// raw: the same mistake #18 fixed on the response side. +// +// So the headers come from Write, which knows what actually goes on the wire +// (Host, User-Agent, Content-Length are none of them in req.Header), and the +// body goes through the shared renderer that crops and hex-dumps. +func writeRequest(w io.Writer, req *http.Request) { + // A fresh clone replays the body; without GetBody there is nothing to + // replay and the dump is no worse than it was. + dump := req + if fresh, err := cloneForAttempt(req); err == nil { + dump = fresh + } + + var b bytes.Buffer + if err := dump.Write(&b); err != nil { + // A failed dump must not replace the failure being reported, so + // whatever was rendered before the error still goes out. + _, _ = w.Write(b.Bytes()) + return + } + + head, body, found := bytes.Cut(b.Bytes(), []byte("\r\n\r\n")) + _, _ = w.Write(head) + _, _ = w.Write([]byte("\r\n\r\n")) + if !found || len(body) == 0 { + return + } + + if cropped := printPayload(w, body, maxPayloadBytes); cropped > 0 { + _, _ = fmt.Fprintf(w, "\n\n << Payload is cropped: %d bytes are hidden >>", cropped) + } +} + func (c Client) getHttpClient() *http.Client { dialer := &net.Dialer{ Timeout: 10 * time.Second, diff --git a/render_test.go b/render_test.go index 032a1c5..99fae3e 100644 --- a/render_test.go +++ b/render_test.go @@ -1,6 +1,7 @@ package main import ( + "io" "net/http" "strings" "testing" @@ -124,3 +125,123 @@ func Test_writeTo_ignoresTransportFraming(t *testing.T) { } } } + +// Test_writeRequest covers the request half of the failure dump. +// +// http.Request.Write was used directly, and by then the transport had drained +// the body -- so the dump advertised a Content-Length with nothing behind it, +// which is both useless (the first question after a failed POST is what was +// sent) and self-contradictory as an HTTP message (#19). +func Test_writeRequest(t *testing.T) { + t.Parallel() + + request := func(t *testing.T, method, body string) *http.Request { + t.Helper() + + var r io.Reader = http.NoBody + if body != "" { + r = strings.NewReader(body) + } + req, err := http.NewRequest(method, "http://example.com/things", r) + if err != nil { + t.Fatalf("cannot build the request: %s", err) + } + return req + } + + // sent drains the body the way http.Client does, so the request under test + // is in the state the dump actually receives. + sent := func(t *testing.T, req *http.Request) *http.Request { + t.Helper() + + attempt, err := cloneForAttempt(req) + if err != nil { + t.Fatalf("cannot clone: %s", err) + } + if _, err := io.ReadAll(attempt.Body); err != nil { + t.Fatalf("cannot drain: %s", err) + } + _ = attempt.Body.Close() + return attempt + } + + t.Run("the body survives having been sent", func(t *testing.T) { + req := sent(t, request(t, "POST", "PAYLOAD")) + + var b strings.Builder + writeRequest(&b, req) + + out := b.String() + if !strings.Contains(out, "PAYLOAD") { + t.Errorf("the dump omits the body it says it sent:\n%s", out) + } + if !strings.Contains(out, "Content-Length: 7") { + t.Errorf("the dump lost Content-Length:\n%s", out) + } + }) + + t.Run("a request with no body dumps cleanly", func(t *testing.T) { + req := sent(t, request(t, "GET", "")) + + var b strings.Builder + writeRequest(&b, req) + + out := b.String() + if !strings.Contains(out, "GET /things HTTP/1.1") { + t.Errorf("the request line is missing:\n%s", out) + } + // No payload section, and nothing pretending there is one. + if strings.Contains(out, "Payload is cropped") { + t.Errorf("an empty body was reported as cropped:\n%s", out) + } + }) + + // The other half of #18's lesson, which was applied to the response and + // not to the request: a wire-format serializer puts the whole payload in + // the report, however long it is. + t.Run("a long body is cropped", func(t *testing.T) { + body := strings.Repeat("x", maxPayloadBytes+44) + req := sent(t, request(t, "POST", body)) + + var b strings.Builder + writeRequest(&b, req) + + out := b.String() + if !strings.Contains(out, "<< Payload is cropped: 44 bytes are hidden >>") { + t.Errorf("a %d-byte body was not cropped:\n%s", len(body), out) + } + // Counted in the body only -- the Host header carries an "x" of its own. + _, payload, found := strings.Cut(out, "\r\n\r\n") + if !found { + t.Fatalf("no header/body separator in the dump:\n%s", out) + } + if n := strings.Count(payload, "x"); n != maxPayloadBytes { + t.Errorf("%d body bytes reached the dump, want %d", n, maxPayloadBytes) + } + }) + + t.Run("a non-printable body is hex-dumped", func(t *testing.T) { + req := sent(t, request(t, "POST", "\xff\xfe\x07\x08")) + + var b strings.Builder + writeRequest(&b, req) + + if out := b.String(); !strings.Contains(out, "ff fe 07 08") { + t.Errorf("a binary body was not hex-dumped:\n%s", out) + } + }) + + // Without GetBody there is nothing to replay. The dump must still render + // the headers rather than failing outright. + t.Run("a body that cannot be replayed still dumps its headers", func(t *testing.T) { + req := sent(t, request(t, "POST", "PAYLOAD")) + req.GetBody = nil + + var b strings.Builder + writeRequest(&b, req) + + if out := b.String(); !strings.Contains(out, "POST /things HTTP/1.1") { + t.Errorf("the headers went missing along with the body:\n%s", out) + } + }) +}