From 50ad48295c3972990b83c5d0cb3c97309971e851 Mon Sep 17 00:00:00 2001 From: korya <148461+korya@users.noreply.github.com> Date: Fri, 7 Aug 2026 22:48:45 -0400 Subject: [PATCH 1/2] fix(render): Format the failure dump instead of serializing it The dump a person reads when an assertion fails was produced by http.Response.Write, an HTTP wire serializer. It honours Content-Length and Transfer-Encoding, which describe the body that arrived -- not the rendering that replaces it before printing. Two consequences, both silent: A rendering longer than the original body was cut to the original's length. A four-byte body reduced " << Payload is omitted >>" to " <<", and an eight-byte binary body reduced its hex dump to the offset "00000000", from a dumper whose entire purpose is showing the bytes. --silent is the mode the README's monitoring example recommends, so the mode most likely to be deployed was the mode that hid the diagnostic. A chunked response has no Content-Length, so instead of truncating, the serializer re-framed the rendering: a hex chunk length, the text, a zero terminator, and a Transfer-Encoding header it invented. Protocol framing in a human-readable report. Go reported the first case every single time -- "http: ContentLength=4 with Body length 26" -- and the caller discarded the error. There is nothing to discard now: the renderer emits the whole output itself, so no length can disagree with it. The response half also drops wire line endings, which show up as ^M in pagers and some CI log viewers. The request half keeps them for now; it is still serialized by http.Request.Write, which synthesizes the User-Agent and Content-Length lines the dump shows. Replacing it belongs with #19, which has to rebuild that half anyway to recover the request body. writeTo no longer reassigns res.Body. It was mutating the caller's response through a value receiver, and closing a body Client.Do had already closed. Closes #18 Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_019EMMhgmTkbzAsmeNy97PrP --- e2e_dump_test.go | 82 +++++++++++++++++++++++++ e2e_known_issues_test.go | 25 -------- e2e_server_test.go | 10 ++++ main.go | 51 ++++++++++++---- render_test.go | 126 +++++++++++++++++++++++++++++++++++++++ 5 files changed, 256 insertions(+), 38 deletions(-) create mode 100644 e2e_dump_test.go create mode 100644 render_test.go diff --git a/e2e_dump_test.go b/e2e_dump_test.go new file mode 100644 index 0000000..1280992 --- /dev/null +++ b/e2e_dump_test.go @@ -0,0 +1,82 @@ +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()) + } + } + }) + + // 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..f0740de 100644 --- a/e2e_server_test.go +++ b/e2e_server_test.go @@ -92,6 +92,16 @@ func testHandler() http.Handler { write(w, http.StatusOK, []byte{0x00, 0x01, 0x02, 0x03, 0xff, 0xfe, 0x07, 0x08}, 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()) + } + } +} From 7b0609773e501073dd92826e6134792e249c537f Mon Sep 17 00:00:00 2001 From: korya <148461+korya@users.noreply.github.com> Date: Fri, 7 Aug 2026 22:50:25 -0400 Subject: [PATCH 2/2] fix(render): Treat whitespace as text when choosing the body renderer MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit unicode.IsPrint answers false for '\n', '\t' and '\r', and isPrintable tested nothing else. So a body with a line break anywhere in its first 256 bytes was classified as binary and sent to the hex dumper: $ http-assert -v --assert-body-eq x http://…/multiline 00000000 6c 69 6e 65 20 6f 6e 65 0a 6c 69 6e 65 20 74 77 |line one.line tw| That is pretty-printed JSON, HTML, and any log excerpt -- most of what a response body actually contains -- rendered in the least readable form available, at the moment somebody is reading it to find out what went wrong. Whitespace is text, so the classifier now says so. Control bytes still route to the dumper: a body mixing newlines with a NUL is binary and reads as binary. Known gap, left alone deliberately and documented at the function: bytes that are not valid UTF-8 decode to U+FFFD, which is printable, so a body of high bytes still reads as text. The obvious utf8.Valid guard is wrong here because cropping happens first and can split a multi-byte rune, which would misfile legitimate text as binary. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_019EMMhgmTkbzAsmeNy97PrP --- e2e_dump_test.go | 9 +++++++++ e2e_server_test.go | 6 ++++++ utils.go | 15 ++++++++++++++- utils_test.go | 27 +++++++++++++++++++++++++++ 4 files changed, 56 insertions(+), 1 deletion(-) diff --git a/e2e_dump_test.go b/e2e_dump_test.go index 1280992..40d0cb1 100644 --- a/e2e_dump_test.go +++ b/e2e_dump_test.go @@ -54,6 +54,15 @@ func TestE2EFailureDump(t *testing.T) { } }) + // 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) { diff --git a/e2e_server_test.go b/e2e_server_test.go index f0740de..f962f65 100644 --- a/e2e_server_test.go +++ b/e2e_server_test.go @@ -92,6 +92,12 @@ 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). 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"),