diff --git a/e2e_dump_test.go b/e2e_dump_test.go new file mode 100644 index 0000000..40d0cb1 --- /dev/null +++ b/e2e_dump_test.go @@ -0,0 +1,91 @@ +package main_test + +import ( + "strings" + "testing" +) + +// The failure dump is the only thing a person reads when an assertion fails, +// so what it contains is part of the contract. +// +// It used to be produced by http.Response.Write, an HTTP wire serializer. That +// honours Content-Length and Transfer-Encoding, which describe the body that +// arrived rather than the rendering that replaces it -- so a rendering longer +// than the original body was cut to the original's length, and a chunked +// response had its framing interleaved with the text (#18). Each test below +// failed before that was fixed. + +func TestE2EFailureDump(t *testing.T) { + // /500 returns a four-byte body, which used to cut the twenty-five byte + // placeholder down to " <<". + t.Run("omitted placeholder is not cut to the body length", func(t *testing.T) { + r := run(t, nil, "-s", "--assert-ok", url("/500")) + assertExit(t, r, exitRequestFail) + assertContains(t, r, " << Payload is omitted >>") + }) + + // Eight raw bytes used to render as the offset "00000000" and nothing + // else, from a dumper whose entire purpose is showing the bytes. + t.Run("binary body keeps its hex dump and ascii gutter", func(t *testing.T) { + r := run(t, nil, "--assert-body-eq", "never-matches", url("/binary")) + assertExit(t, r, exitRequestFail) + assertContains(t, r, "00000000") + assertContains(t, r, "00 01 02 03 ff fe 07 08") + assertContains(t, r, "|") + }) + + // A chunked response has no Content-Length, so instead of truncating, the + // serializer re-framed the rendering: a hex length, then the text, then a + // zero terminator, plus a Transfer-Encoding header it invented. + t.Run("chunked response is dumped without transfer framing", func(t *testing.T) { + r := run(t, nil, "-v", "--assert-body-eq", "never-matches", url("/chunked")) + assertExit(t, r, exitRequestFail) + assertContains(t, r, "first chunk second chunk") + assertNotContains(t, r, "Transfer-Encoding") + + // "18" is the chunk length the serializer used to emit for this body. + // Anchored to line starts so a chunk length is not confused with the + // same digits inside a header value or a timing. + dump, _, _ := strings.Cut(r.Output(), "first chunk") + for line := range strings.SplitSeq(dump, "\n") { + if strings.TrimSpace(line) == "18" || strings.TrimSpace(line) == "0" { + t.Fatalf("chunk framing leaked into the dump:\n%s", r.Output()) + } + } + }) + + // unicode.IsPrint answers false for '\n', so a body with a line break in it + // -- pretty-printed JSON, HTML, a log excerpt -- was shown as a hex dump. + t.Run("multi-line text body is shown as text", func(t *testing.T) { + r := run(t, nil, "--assert-body-eq", "never-matches", url("/multiline")) + assertExit(t, r, exitRequestFail) + assertContains(t, r, "\"status\": \"success\"") + assertNotContains(t, r, "00000000") + }) + + // Cropping is a property of the renderer, not of the transport, and has to + // survive the change. + t.Run("large body is still cropped and says so", func(t *testing.T) { + r := run(t, nil, "--assert-body-eq", "never-matches", url("/big")) + assertExit(t, r, exitRequestFail) + assertContains(t, r, "Payload is cropped") + assertContains(t, r, "bytes are hidden") + }) + + // Wire line endings in a human-readable report show up as ^M in pagers and + // some CI log viewers. + t.Run("dump uses newlines rather than wire line endings", func(t *testing.T) { + r := run(t, nil, "-s", "--assert-ok", url("/500")) + assertExit(t, r, exitRequestFail) + + // The request half is still serialized by http.Request.Write and keeps + // its CRLFs; #19 replaces it. Only the response half is checked here. + _, dump, found := strings.Cut(r.Output(), "HTTP/1.1 500") + if !found { + t.Fatalf("no response status line in the dump\n%s", r.Output()) + } + if strings.Contains(dump, "\r") { + t.Errorf("response dump contains a carriage return: %q", dump) + } + }) +} diff --git a/e2e_known_issues_test.go b/e2e_known_issues_test.go index e589f3e..af43fb4 100644 --- a/e2e_known_issues_test.go +++ b/e2e_known_issues_test.go @@ -46,31 +46,6 @@ func TestIssue17BadPatternIsRejected(t *testing.T) { }) } -// TestKnownIssue18PayloadTruncated: the response dump replaces the body with a -// rendered form but leaves Content-Length untouched, so http.Response.Write -// truncates whatever it renders to the original byte count. -func TestKnownIssue18PayloadTruncated(t *testing.T) { - t.Run("silent mode truncates the placeholder", func(t *testing.T) { - characterizes(t, 18, "'<< Payload is omitted >>' is cut to the body's length") - - // The body is "boom" (4 bytes), so only 4 bytes of the placeholder survive. - r := run(t, nil, "-s", "--assert-ok", url("/500")) - assertExit(t, r, exitRequestFail) - assertContains(t, r, " <<") - assertNotContains(t, r, "Payload is omitted >>") - }) - - t.Run("binary body truncates the hex dump", func(t *testing.T) { - characterizes(t, 18, "an 8-byte binary body renders as a single hex offset") - - r := run(t, nil, "--assert-body-eq", "never-matches", url("/binary")) - assertExit(t, r, exitRequestFail) - assertContains(t, r, "00000000") - // The real dump would carry the bytes and an ASCII gutter. - assertNotContains(t, r, "|") - }) -} - // 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) { diff --git a/e2e_server_test.go b/e2e_server_test.go index 940e61a..f962f65 100644 --- a/e2e_server_test.go +++ b/e2e_server_test.go @@ -92,6 +92,22 @@ func testHandler() http.Handler { write(w, http.StatusOK, []byte{0x00, 0x01, 0x02, 0x03, 0xff, 0xfe, 0x07, 0x08}, nil) }) + // A multi-line text body: the shape most real responses have, and the one + // that used to reach the hex dumper because '\n' is not unicode.IsPrint. + mux.HandleFunc("/multiline", func(w http.ResponseWriter, _ *http.Request) { + write(w, http.StatusOK, []byte("{\n \"status\": \"success\"\n}"), nil) + }) + + // Flushes before the response buffer fills, which forces chunked transfer + // and leaves Content-Length unset. The failure dump must show the body + // without the framing that carried it (#18). + mux.HandleFunc("/chunked", func(w http.ResponseWriter, _ *http.Request) { + w.Header().Set("Content-Type", "text/plain") + _, _ = w.Write([]byte("first chunk ")) + w.(http.Flusher).Flush() + _, _ = w.Write([]byte("second chunk")) + }) + // Larger than the 256-byte crop threshold used when printing payloads. mux.HandleFunc("/big", func(w http.ResponseWriter, _ *http.Request) { body := make([]byte, 5000) diff --git a/main.go b/main.go index f9c4eb1..885e71f 100644 --- a/main.go +++ b/main.go @@ -38,15 +38,16 @@ package main import ( - "bytes" "context" "crypto/tls" "errors" "fmt" "io" + "maps" "net" "net/http" "os" + "slices" "strconv" "strings" "time" @@ -496,21 +497,45 @@ type httpResponse struct { BodyBytes []byte } +// maxPayloadBytes is how much of a body the failure dump shows before cropping. +const maxPayloadBytes = 256 + +// writeTo renders the response for a person reading a failure report. +// +// Deliberately not http.Response.Write. That is a wire-format serializer: it +// honours ContentLength and Transfer-Encoding, which describe the body that +// arrived rather than the rendering that replaces it here. A placeholder or a +// hex dump longer than the original body was cut to the original's length, and +// a chunked response had its framing interleaved with the rendering (#18). +// +// Go reported the mismatch on every such run -- "http: ContentLength=4 with +// Body length 26" -- and the caller discarded it. Nothing to discard now: the +// bytes below are the whole output. +// +// Write errors are ignored, following utils.go, because every caller renders +// into an in-memory strings.Builder that cannot fail. func (r httpResponse) writeTo(w io.Writer, withBody bool) { - // Ensure to close previous body - b := r.Body - defer func() { _ = b.Close() }() - if withBody { - var b bytes.Buffer - croppedBytes := printPayload(&b, r.BodyBytes, 256) - if croppedBytes > 0 { - fmt.Fprintf(&b, "\n\n << Payload is cropped: %d bytes are hidden >>", croppedBytes) + _, _ = fmt.Fprintf(w, "%s %s\n", r.Proto, r.Status) + writeHeaders(w, r.Header) + _, _ = fmt.Fprintln(w) + + if !withBody { + _, _ = fmt.Fprint(w, " << Payload is omitted >>") + return + } + if cropped := printPayload(w, r.BodyBytes, maxPayloadBytes); cropped > 0 { + _, _ = fmt.Fprintf(w, "\n\n << Payload is cropped: %d bytes are hidden >>", cropped) + } +} + +// writeHeaders renders headers one per line, sorted by name so that two dumps +// of the same response can be compared. +func writeHeaders(w io.Writer, h http.Header) { + for _, name := range slices.Sorted(maps.Keys(h)) { + for _, value := range h[name] { + _, _ = fmt.Fprintf(w, "%s: %s\n", name, value) } - r.Body = io.NopCloser(&b) - } else { - r.Body = io.NopCloser(strings.NewReader(" << Payload is omitted >>")) } - _ = r.Write(w) } type hostMapping struct { diff --git a/render_test.go b/render_test.go new file mode 100644 index 0000000..032a1c5 --- /dev/null +++ b/render_test.go @@ -0,0 +1,126 @@ +package main + +import ( + "net/http" + "strings" + "testing" +) + +// response builds the shape Client.Do hands to the renderer: a real +// *http.Response plus the body already read off the wire. +func response(status string, header http.Header, body string) httpResponse { + return httpResponse{ + Response: &http.Response{ + Proto: "HTTP/1.1", + Status: status, + Header: header, + // Set deliberately, and deliberately inconsistent with the body + // below: the renderer must describe what it prints, not what the + // transport said would arrive (#18). + ContentLength: int64(len(body)), + TransferEncoding: []string{"chunked"}, + }, + BodyBytes: []byte(body), + } +} + +func Test_httpResponse_writeTo(t *testing.T) { + t.Parallel() + + plain := http.Header{"Content-Type": {"text/plain"}} + + tests := []struct { + Name string + Response httpResponse + WithBody bool + Want string + }{{ + Name: "status line, headers, body", + Response: response("200 OK", plain, "hello"), + WithBody: true, + Want: "HTTP/1.1 200 OK\n" + + "Content-Type: text/plain\n" + + "\n" + + "hello", + }, { + // The case #18 opens with: the placeholder is longer than the body it + // stands in for, and used to be cut to the body's length. + Name: "omitted payload survives a shorter body", + Response: response("500 Internal Server Error", plain, "boom"), + WithBody: false, + Want: "HTTP/1.1 500 Internal Server Error\n" + + "Content-Type: text/plain\n" + + "\n" + + " << Payload is omitted >>", + }, { + Name: "headers are sorted and repeated values kept", + Response: response("200 OK", http.Header{"Set-Cookie": {"a=1", "b=2"}, "Allow": {"GET"}}, ""), + WithBody: true, + Want: "HTTP/1.1 200 OK\n" + + "Allow: GET\n" + + "Set-Cookie: a=1\n" + + "Set-Cookie: b=2\n" + + "\n", + }, { + Name: "no headers still leaves the blank separator", + Response: response("204 No Content", http.Header{}, ""), + WithBody: true, + Want: "HTTP/1.1 204 No Content\n\n", + }, { + // A body of raw bytes goes to the hex dumper, gutter and all -- the + // whole point of the dumper, and what truncation used to remove. + Name: "binary body renders as a full hex dump", + Response: response("200 OK", http.Header{}, "\x00\x01\x02\xff"), + WithBody: true, + Want: "HTTP/1.1 200 OK\n" + + "\n" + + "00000000 00 01 02 ff |....|\n", + }} + + for _, tc := range tests { + t.Run(tc.Name, func(t *testing.T) { + var b strings.Builder + tc.Response.writeTo(&b, tc.WithBody) + + if got := b.String(); got != tc.Want { + t.Errorf("writeTo()\n got: %q\nwant: %q", got, tc.Want) + } + }) + } +} + +// Test_httpResponse_writeToCrops covers the branch that reports hidden bytes. +// It is separate because the expected text depends on the crop limit. +func Test_httpResponse_writeToCrops(t *testing.T) { + t.Parallel() + + body := strings.Repeat("x", maxPayloadBytes+17) + var b strings.Builder + response("200 OK", http.Header{}, body).writeTo(&b, true) + + got := b.String() + if want := strings.Repeat("x", maxPayloadBytes); !strings.Contains(got, want) { + t.Errorf("writeTo() did not render the first %d bytes", maxPayloadBytes) + } + if want := "<< Payload is cropped: 17 bytes are hidden >>"; !strings.Contains(got, want) { + t.Errorf("writeTo() = %q, want it to contain %q", got, want) + } +} + +// Test_writeTo_ignoresTransportFraming states the property #18 is really about: +// nothing describing how the body travelled may reach the reader. The response +// above advertises chunked transfer and a ContentLength that contradicts the +// rendering, and neither may show up. +func Test_writeTo_ignoresTransportFraming(t *testing.T) { + t.Parallel() + + var b strings.Builder + response("200 OK", http.Header{"Content-Type": {"text/plain"}}, "boom"). + writeTo(&b, false) + + for _, unwanted := range []string{"chunked", "Transfer-Encoding", "\r"} { + if strings.Contains(b.String(), unwanted) { + t.Errorf("writeTo() leaked %q into the dump:\n%s", unwanted, b.String()) + } + } +} diff --git a/utils.go b/utils.go index 4ca7f8d..6c8b0f1 100644 --- a/utils.go +++ b/utils.go @@ -43,9 +43,22 @@ func printPayload(w io.Writer, bs []byte, maxSize int) (croppedBytes int) { return } +// isPrintable reports whether bs should be shown as text rather than dumped as +// hex. +// +// Whitespace counts as text. unicode.IsPrint answers false for '\n', '\t' and +// '\r', so testing it alone sent every multi-line body -- pretty-printed JSON, +// HTML, a log excerpt, anything with a line break in the first 256 bytes -- to +// the hex dumper, which is the least readable way to show text a human was +// about to read. +// +// Known gap: bytes that are not valid UTF-8 decode to U+FFFD, which is itself +// printable, so a body of high bytes still reads as text. Cropping happens +// before this check and can split a multi-byte rune, so the obvious utf8.Valid +// guard would misfile legitimate text; tracked separately. func isPrintable(bs []byte) bool { nonPrintableIdx := bytes.IndexFunc(bs, func(r rune) bool { - return !unicode.IsPrint(r) + return !unicode.IsPrint(r) && !unicode.IsSpace(r) }) return nonPrintableIdx < 0 } diff --git a/utils_test.go b/utils_test.go index e06df0b..57bfd52 100644 --- a/utils_test.go +++ b/utils_test.go @@ -90,6 +90,33 @@ func Test_printPayload(t *testing.T) { Output: "", CroppedBytes: 11, }, + // Whitespace is text. unicode.IsPrint rejects it, so testing that alone + // sent every body with a line break through the hex dumper. + { + CaseName: "multiple lines stay text", + Input: []byte("line one\nline two\nline three"), + MaxSize: 100, + Output: "line one\nline two\nline three", + }, + { + CaseName: "pretty-printed JSON stays text", + Input: []byte("{\n \"ok\": true\n}"), + MaxSize: 100, + Output: "{\n \"ok\": true\n}", + }, + { + CaseName: "tabs and carriage returns stay text", + Input: []byte("a\tb\r\nc"), + MaxSize: 100, + Output: "a\tb\r\nc", + }, + { + CaseName: "a control byte among the whitespace is still binary", + Input: []byte("line one\nline\x00two"), + MaxSize: 100, + Output: "00000000 6c 69 6e 65 20 6f 6e 65 0a 6c 69 6e 65 00 74 77 |line one.line.tw|\n" + + "00000010 6f |o|\n", + }, { CaseName: "single line, BIN, 100", Input: []byte("\x01single\x00line"),