From 21723dcc573b847d937206b1da4ae09e7c1a798d Mon Sep 17 00:00:00 2001 From: Bozhidar Batsov Date: Wed, 7 Oct 2026 15:32:45 +0300 Subject: [PATCH 1/4] Keep the bytes of a cut-off string in Raw When the input ended in the middle of a string, the decoder dropped the part of the string it had already read, so Raw was missing bytes that were consumed. The excerpt of such a broken frame was shorter than what the server actually sent. --- bencode/bencode_test.go | 8 ++++++-- bencode/decode.go | 11 +++++++---- 2 files changed, 13 insertions(+), 6 deletions(-) diff --git a/bencode/bencode_test.go b/bencode/bencode_test.go index 1aabe75..7ff56dd 100644 --- a/bencode/bencode_test.go +++ b/bencode/bencode_test.go @@ -100,10 +100,14 @@ func TestDecodeSyntaxErrors(t *testing.T) { } func TestDecodeTruncated(t *testing.T) { - for _, in := range []string{"i42", "4:sp", "l4:spam", "d2:id"} { - if _, err := decodeOne(t, in); !errors.Is(err, io.ErrUnexpectedEOF) { + for _, in := range []string{"i42", "4:sp", "l4:spam", "d2:id", "d4:code10:(+ 1"} { + v, err := decodeOne(t, in) + if !errors.Is(err, io.ErrUnexpectedEOF) { t.Errorf("%q: got %v, want io.ErrUnexpectedEOF", in, err) } + if string(v.Raw) != in { + t.Errorf("%q: raw is %q", in, v.Raw) + } } } diff --git a/bencode/decode.go b/bencode/decode.go index 2613c1c..341270b 100644 --- a/bencode/decode.go +++ b/bencode/decode.go @@ -65,7 +65,9 @@ func NewDecoder(r io.Reader) *Decoder { // Value is one decoded top-level value. type Value struct { - Data any + Data any + // Raw is every byte the decoder consumed, which after an error is the + // value up to the point where it went wrong. Raw []byte Violations []Violation } @@ -266,13 +268,14 @@ func (d *Decoder) str() (string, error) { } } buf := make([]byte, n) - if _, err := io.ReadFull(d.r, buf); err != nil { + read, err := io.ReadFull(d.r, buf) + d.off += int64(read) + d.raw = append(d.raw, buf[:read]...) + if err != nil { if errors.Is(err, io.EOF) { err = io.ErrUnexpectedEOF } return "", err } - d.off += int64(n) - d.raw = append(d.raw, buf...) return string(buf), nil } From b25800539c1aae4b5c5846cf2c42fb2915586f66 Mon Sep 17 00:00:00 2001 From: Bozhidar Batsov Date: Wed, 7 Oct 2026 15:33:24 +0300 Subject: [PATCH 2/4] Prepare the rule machinery for grading client traffic Checking what a client sends takes the same pieces the wire rules use for replies. The frame checks now take a direction, turning a decoded frame into an event lives in nrepl.DecodeEvent, and Grade and Transcript are exported. Traffic.Check becomes Label, as a client's traffic is labelled by connection rather than by check, and replies are matched to requests by ids of any type, not just strings. --- cmd/proof/main.go | 23 +++++-- internal/check/check.go | 7 +-- internal/check/rule.go | 31 +++++++--- internal/check/rule_test.go | 6 +- internal/checks/checks_test.go | 52 ++++++++-------- internal/checks/wire.go | 108 ++++++++++++++++++++++----------- internal/report/report.go | 6 +- nrepl/conn.go | 50 +++++++++------ nrepl/conn_test.go | 59 ++++++++++++++++++ 9 files changed, 235 insertions(+), 107 deletions(-) create mode 100644 nrepl/conn_test.go diff --git a/cmd/proof/main.go b/cmd/proof/main.go index 0d0fa79..4c4eaaa 100644 --- a/cmd/proof/main.go +++ b/cmd/proof/main.go @@ -137,9 +137,7 @@ func run(args []string) int { for _, id := range outcome.Stale { fmt.Printf("%s is listed in expected-failures but didn't fail; remove it from the profile\n", id) } - if srv != nil && !srv.Alive() { - fmt.Printf("\nThe server exited during the run. Its output:\n%s", srv.Output()) - } + showDeath(os.Stdout, srv) if opts.json != "" { if err := writeJSON(opts.json, r); err != nil { fmt.Fprintln(os.Stderr, "proof:", err) @@ -181,6 +179,14 @@ func startServer(p *profile.Profile) (*server.Server, error) { return srv, err } +// showDeath shows the output of a server that exited while proof was +// using it, as that explains whatever went wrong afterwards. +func showDeath(w io.Writer, srv *server.Server) { + if srv != nil && !srv.Alive() { + fmt.Fprintf(w, "\nThe server exited during the run. Its output:\n%s", srv.Output()) + } +} + func writeJSON(path string, r report.Run) error { f, err := os.Create(path) if err != nil { @@ -204,10 +210,15 @@ func catalog() []entry { for _, c := range checks.All() { all = append(all, entry{c.ID, c.Title, c.Severity}) } - for _, r := range checks.WireRules() { - all = append(all, entry{r.ID, r.Title, r.Severity}) + return append(all, ruleEntries(checks.WireRules())...) +} + +func ruleEntries(rules []*check.Rule) []entry { + var entries []entry + for _, r := range rules { + entries = append(entries, entry{r.ID, r.Title, r.Severity}) } - return all + return entries } func allIDs() []string { diff --git a/internal/check/check.go b/internal/check/check.go index 1252060..0263ade 100644 --- a/internal/check/check.go +++ b/internal/check/check.go @@ -275,16 +275,13 @@ func Run(env *Env, checks []*Check, rules []*Rule) []Result { for _, conn := range conns[i] { tr := conn.Transcript() transcripts = append(transcripts, tr) - traffic = append(traffic, Traffic{Check: c.ID, Events: tr}) + traffic = append(traffic, Traffic{Label: c.ID, Events: tr}) } if v := results[i].Verdict; v != Pass && v != Skipped { results[i].Transcripts = transcripts } } - for _, rule := range rules { - results = append(results, rule.grade(traffic)) - } - return results + return append(results, Grade(rules, traffic)...) } func runOne(env *Env, c *Check, earlier map[string]Verdict) (Result, []*nrepl.Conn) { diff --git a/internal/check/rule.go b/internal/check/rule.go index fda9dfd..5284840 100644 --- a/internal/check/rule.go +++ b/internal/check/rule.go @@ -6,10 +6,11 @@ import ( "github.com/nrepl/proof/nrepl" ) -// Traffic is one connection's transcript, tagged with the check that -// opened it. +// Traffic is one connection's transcript. type Traffic struct { - Check string + // Label says where the connection came from: the check that opened + // it, or for a client's traffic, the connection's number. + Label string Events []nrepl.Event } @@ -33,26 +34,38 @@ type Reporter func(problem, example string) const maxRuleDetails = 5 +// Grade grades recorded traffic against each rule. +func Grade(rules []*Rule, traffic []Traffic) []Result { + results := make([]Result, 0, len(rules)) + for _, r := range rules { + results = append(results, r.grade(traffic)) + } + return results +} + // grade collapses identical problems, since a misbehaving server tends to // repeat the same mistake in every message. func (r *Rule) grade(traffic []Traffic) Result { res := Result{ID: r.ID, Title: r.Title, Severity: r.Severity, Why: r.Why, Refs: r.Refs, Verdict: Pass} type problem struct { - text, example, firstCheck string + text, example, firstLabel string count int } var problems []*problem seen := map[string]*problem{} - for _, tr := range traffic { - r.Inspect(tr.Events, func(text, example string) { + reporter := func(tr Traffic) Reporter { + return func(text, example string) { if p, ok := seen[text]; ok { p.count++ return } - p := &problem{text: text, example: example, firstCheck: tr.Check, count: 1} + p := &problem{text: text, example: example, firstLabel: tr.Label, count: 1} seen[text] = p problems = append(problems, p) - }) + } + } + for _, tr := range traffic { + r.Inspect(tr.Events, reporter(tr)) } for i, p := range problems { if i == maxRuleDetails { @@ -63,7 +76,7 @@ func (r *Rule) grade(traffic []Traffic) Result { if p.count > 1 { times = fmt.Sprintf("%d times, first ", p.count) } - d := fmt.Sprintf("%s (%sduring %s)", p.text, times, p.firstCheck) + d := fmt.Sprintf("%s (%sduring %s)", p.text, times, p.firstLabel) if p.example != "" { d += ": " + truncate(p.example, 200) } diff --git a/internal/check/rule_test.go b/internal/check/rule_test.go index d691037..1ac5923 100644 --- a/internal/check/rule_test.go +++ b/internal/check/rule_test.go @@ -15,8 +15,8 @@ func TestGradeCollapsesRepeatedProblems(t *testing.T) { report("status is a string", "") }} traffic := []Traffic{ - {Check: "a", Events: make([]nrepl.Event, 2)}, - {Check: "b", Events: make([]nrepl.Event, 1)}, + {Label: "a", Events: make([]nrepl.Event, 2)}, + {Label: "b", Events: make([]nrepl.Event, 1)}, } res := rule.grade(traffic) if res.Verdict != Failed { @@ -33,7 +33,7 @@ func TestGradeCollapsesRepeatedProblems(t *testing.T) { func TestGradePassesCleanTraffic(t *testing.T) { rule := &Rule{ID: "wire.x", Severity: Fail, Inspect: func([]nrepl.Event, Reporter) {}} - if res := rule.grade([]Traffic{{Check: "a"}}); res.Verdict != Pass || len(res.Details) != 0 { + if res := rule.grade([]Traffic{{Label: "a"}}); res.Verdict != Pass || len(res.Details) != 0 { t.Errorf("got %s %v", res.Verdict, res.Details) } } diff --git a/internal/checks/checks_test.go b/internal/checks/checks_test.go index 99ecae1..be5ba97 100644 --- a/internal/checks/checks_test.go +++ b/internal/checks/checks_test.go @@ -37,12 +37,34 @@ func runFake(t *testing.T, q quirks) map[string]check.Result { return results } -func TestWellBehavedServerPassesEverything(t *testing.T) { - for id, r := range runFake(t, quirks{}) { - if r.Verdict != check.Pass { - t.Errorf("%s: %s %v", id, r.Verdict, r.Details) +// checkVerdicts makes sure each check or rule in want got the listed +// verdict, and that everything else passed. +func checkVerdicts(t *testing.T, results map[string]check.Result, want map[string]check.Verdict) { + t.Helper() + var ids []string + for id := range results { + ids = append(ids, id) + } + sort.Strings(ids) + for _, id := range ids { + r := results[id] + w, listed := want[id] + if !listed { + w = check.Pass + } + if r.Verdict != w { + t.Errorf("%s: got %s, want %s %v", id, r.Verdict, w, r.Details) } } + for id := range want { + if _, ok := results[id]; !ok { + t.Errorf("%s: no such check or rule", id) + } + } +} + +func TestWellBehavedServerPassesEverything(t *testing.T) { + checkVerdicts(t, runFake(t, quirks{}), nil) } // Each misbehaviour must produce exactly the listed verdicts, and every @@ -103,27 +125,7 @@ func TestChecksCatchMisbehaviour(t *testing.T) { for _, c := range cases { t.Run(c.name, func(t *testing.T) { t.Parallel() - results := runFake(t, c.q) - var ids []string - for id := range results { - ids = append(ids, id) - } - sort.Strings(ids) - for _, id := range ids { - r := results[id] - want, listed := c.want[id] - if !listed { - want = check.Pass - } - if r.Verdict != want { - t.Errorf("%s: got %s, want %s %v", id, r.Verdict, want, r.Details) - } - } - for id := range c.want { - if _, ok := results[id]; !ok { - t.Errorf("%s: no such check", id) - } - } + checkVerdicts(t, runFake(t, c.q), c.want) }) } } diff --git a/internal/checks/wire.go b/internal/checks/wire.go index 25b4b07..ee6cac0 100644 --- a/internal/checks/wire.go +++ b/internal/checks/wire.go @@ -30,17 +30,7 @@ func WireRules() []*check.Rule { Severity: check.Fail, Why: "A client's decoder stops at the first broken frame, and the connection is lost with it.", Refs: []check.Ref{specProtocol}, - Inspect: eachReceived(func(ev nrepl.Event, report check.Reporter) { - if ev.Err == nil { - return - } - problem := ev.Err.Error() - var se *bencode.SyntaxError - if errors.As(ev.Err, &se) { - problem = se.Msg - } - report(problem, excerpt(ev.Raw)) - }), + Inspect: eachReceived(badFrame), }, { ID: "wire.dict", @@ -48,11 +38,7 @@ func WireRules() []*check.Rule { Severity: check.Fail, Why: "Clients look up id, status and the rest by key; any other top-level value can't be routed.", Refs: []check.Ref{specProtocol}, - Inspect: eachReceived(func(ev nrepl.Event, report check.Reporter) { - if ev.Err == nil && ev.Msg == nil { - report("a top-level "+typeName(ev.Data)+" instead of a dict", excerpt(ev.Raw)) - } - }), + Inspect: eachReceived(notDict), }, { ID: "wire.canonical", @@ -60,11 +46,7 @@ func WireRules() []*check.Rule { Severity: check.Warn, Why: "Clients tolerate unsorted keys and leading zeros today, but it's invalid bencode and a stricter decoder would reject it.", Refs: []check.Ref{specProtocol}, - Inspect: eachReceived(func(ev nrepl.Event, report check.Reporter) { - for _, v := range ev.Violations { - report(v.Msg, "") - } - }), + Inspect: eachReceived(nonCanonical), }, { ID: "wire.utf8", @@ -110,13 +92,7 @@ func WireRules() []*check.Rule { Why: "Clients insert id, session, ns, value, out and err straight into buffers and prompts; other types break them.", Refs: []check.Ref{specEval, ciderPayloadCond}, Inspect: eachMessage(func(m nrepl.Message, report check.Reporter) { - for _, k := range stringFields { - if m.Has(k) { - if _, ok := m[k].(string); !ok { - report(k+" is "+typeName(m[k]), m.String()) - } - } - } + wrongTypes[string](m, stringFields, report) }), }, { @@ -227,24 +203,69 @@ func WireRules() []*check.Rule { } } -func eachReceived(f func(nrepl.Event, check.Reporter)) func([]nrepl.Event, check.Reporter) { +// eachFrame calls f for every frame that went in the given direction. +func eachFrame(dir nrepl.Direction, f func(nrepl.Event, check.Reporter)) func([]nrepl.Event, check.Reporter) { return func(events []nrepl.Event, report check.Reporter) { for _, ev := range events { - if ev.Dir == nrepl.Received { + if ev.Dir == dir { f(ev, report) } } } } -func eachMessage(f func(nrepl.Message, check.Reporter)) func([]nrepl.Event, check.Reporter) { - return eachReceived(func(ev nrepl.Event, report check.Reporter) { +func eachReceived(f func(nrepl.Event, check.Reporter)) func([]nrepl.Event, check.Reporter) { + return eachFrame(nrepl.Received, f) +} + +func badFrame(ev nrepl.Event, report check.Reporter) { + if ev.Err == nil { + return + } + problem := ev.Err.Error() + var se *bencode.SyntaxError + if errors.As(ev.Err, &se) { + problem = se.Msg + } + report(problem, excerpt(ev.Raw)) +} + +func notDict(ev nrepl.Event, report check.Reporter) { + if ev.Err == nil && ev.Msg == nil { + report("a top-level "+typeName(ev.Data)+" instead of a dict", excerpt(ev.Raw)) + } +} + +func nonCanonical(ev nrepl.Event, report check.Reporter) { + for _, v := range ev.Violations { + report(v.Msg, "") + } +} + +// wrongTypes reports each of fields that m has, but not as a T. +func wrongTypes[T any](m nrepl.Message, fields []string, report check.Reporter) { + for _, k := range fields { + if v, ok := m[k]; ok { + if _, ok := v.(T); !ok { + report(k+" is "+typeName(v), m.String()) + } + } + } +} + +// eachMessageIn calls f for every dict that went in the given direction. +func eachMessageIn(dir nrepl.Direction, f func(nrepl.Message, check.Reporter)) func([]nrepl.Event, check.Reporter) { + return eachFrame(dir, func(ev nrepl.Event, report check.Reporter) { if ev.Msg != nil { f(ev.Msg, report) } }) } +func eachMessage(f func(nrepl.Message, check.Reporter)) func([]nrepl.Event, check.Reporter) { + return eachMessageIn(nrepl.Received, f) +} + // reply is a received message along with what came before it on the // connection. type reply struct { @@ -252,11 +273,21 @@ type reply struct { // Req is the request the reply's id refers to, or nil. Req nrepl.Message // AfterDone and AfterError say whether an earlier message for the same - // request carried done, or an error status. Replies without a string - // id can't be tied to a request, so both stay false for them. + // request carried done, or an error status. Replies without an id + // can't be tied to a request, so both stay false for them. AfterDone, AfterError bool } +// idKey tells ids of different types apart, since servers echo whatever +// they got. +func idKey(m nrepl.Message) (string, bool) { + v, ok := m["id"] + if !ok { + return "", false + } + return fmt.Sprintf("%T %v", v, v), true +} + // eachReply walks a connection once, annotating every received message. func eachReply(f func(reply, check.Reporter)) func([]nrepl.Event, check.Reporter) { return func(events []nrepl.Event, report check.Reporter) { @@ -266,13 +297,16 @@ func eachReply(f func(reply, check.Reporter)) func([]nrepl.Event, check.Reporter if ev.Msg == nil { continue } + id, hasID := idKey(ev.Msg) if ev.Dir == nrepl.Sent { - sent[ev.Msg.Str("id")] = ev.Msg + if hasID { + sent[id] = ev.Msg + } continue } - id, hasID := ev.Msg["id"].(string) - r := reply{Msg: ev.Msg, Req: sent[id]} + r := reply{Msg: ev.Msg} if hasID { + r.Req = sent[id] r.AfterDone, r.AfterError = done[id], errored[id] } f(r, report) diff --git a/internal/report/report.go b/internal/report/report.go index 433ac4a..fcafe7a 100644 --- a/internal/report/report.go +++ b/internal/report/report.go @@ -68,7 +68,7 @@ func Text(w io.Writer, run Run, verbose bool) { } for i, tr := range res.Transcripts { fmt.Fprintf(w, " connection %d:\n", i+1) - writeTranscript(w, tr, " ") + Transcript(w, tr, " ") } } } @@ -94,7 +94,9 @@ func (r Run) expectedFailures() int { return n } -func writeTranscript(w io.Writer, events []nrepl.Event, indent string) { +// Transcript writes the events of a connection, one per line, with times +// relative to the first one. +func Transcript(w io.Writer, events []nrepl.Event, indent string) { if len(events) == 0 { return } diff --git a/nrepl/conn.go b/nrepl/conn.go index 86f87cf..a72ad8d 100644 --- a/nrepl/conn.go +++ b/nrepl/conn.go @@ -32,13 +32,34 @@ type Event struct { // Data is the decoded value, whatever its type. Data any Raw []byte - // Violations are non-fatal encoding problems in a received frame. + // Violations are non-fatal encoding problems in the frame. Violations []bencode.Violation - // Err is set when a received frame couldn't be decoded. It's the last - // event on the connection. + // Err is set when a frame couldn't be decoded. Nothing that came after + // it on the connection was decoded. Err error } +// DecodeEvent records what bencode.Decoder.Decode returned: a frame, or +// a frame that couldn't be decoded. It returns false when the stream ended +// between frames or broke off (e.g. it was reset), which isn't a problem +// with the encoding. +func DecodeEvent(dir Direction, v bencode.Value, err error) (Event, bool) { + ev := Event{Dir: dir, Time: time.Now(), Raw: v.Raw} + var se *bencode.SyntaxError + switch { + case err == nil: + ev.Data, ev.Violations = v.Data, v.Violations + if m, ok := v.Data.(map[string]any); ok { + ev.Msg = Message(m) + } + case errors.As(err, &se) || errors.Is(err, io.ErrUnexpectedEOF): + ev.Err = err + default: + return Event{}, false + } + return ev, true +} + // Conn is a connection to an nREPL server. type Conn struct { nc net.Conn @@ -77,26 +98,15 @@ func (c *Conn) readLoop() { for { v, err := dec.Decode() c.mu.Lock() - if err != nil { - // Only a frame that failed to decode goes in the transcript; a - // clean close or a reset between frames isn't the server - // breaking the encoding. - var se *bencode.SyntaxError - if errors.As(err, &se) || errors.Is(err, io.ErrUnexpectedEOF) { - c.events = append(c.events, Event{Dir: Received, Time: time.Now(), Raw: v.Raw, Err: err}) - } - c.readErr = err - c.notifyLocked() - c.mu.Unlock() - return - } - ev := Event{Dir: Received, Time: time.Now(), Data: v.Data, Raw: v.Raw, Violations: v.Violations} - if m, ok := v.Data.(map[string]any); ok { - ev.Msg = Message(m) + if ev, ok := DecodeEvent(Received, v, err); ok { + c.events = append(c.events, ev) } - c.events = append(c.events, ev) + c.readErr = err c.notifyLocked() c.mu.Unlock() + if err != nil { + return + } } } diff --git a/nrepl/conn_test.go b/nrepl/conn_test.go new file mode 100644 index 0000000..1ea41f6 --- /dev/null +++ b/nrepl/conn_test.go @@ -0,0 +1,59 @@ +package nrepl + +import ( + "errors" + "io" + "net" + "strings" + "syscall" + "testing" + + "github.com/nrepl/proof/bencode" +) + +func TestDecodeEvent(t *testing.T) { + reset := &net.OpError{Op: "read", Net: "tcp", Err: syscall.ECONNRESET} + closed := &net.OpError{Op: "read", Net: "tcp", Err: net.ErrClosed} + cases := []struct { + name string + raw string + err error + frame bool + broken bool + message bool + }{ + {"a dict", "d2:id1:1e", nil, true, false, true}, + {"a list", "le", nil, true, false, false}, + {"a byte that can't start a value", "", &bencode.SyntaxError{Msg: "unexpected byte 'x'"}, true, true, false}, + {"a frame cut off by the end", "d4:code", io.ErrUnexpectedEOF, true, true, false}, + {"a frame cut off by a reset", "d4:code", reset, false, false, false}, + {"the end between frames", "", io.EOF, false, false, false}, + {"a reset between frames", "", reset, false, false, false}, + {"proof closing the connection", "d4:code", closed, false, false, false}, + } + for _, c := range cases { + t.Run(c.name, func(t *testing.T) { + var data any + if c.err == nil { + v, err := bencode.NewDecoder(strings.NewReader(c.raw)).Decode() + if err != nil { + t.Fatal(err) + } + data = v.Data + } + ev, frame := DecodeEvent(Sent, bencode.Value{Data: data, Raw: []byte(c.raw)}, c.err) + if frame != c.frame { + t.Fatalf("frame: got %v, want %v", frame, c.frame) + } + if broken := ev.Err != nil; broken != c.broken { + t.Errorf("broken: got %v, want %v", broken, c.broken) + } + if c.broken && !errors.Is(ev.Err, c.err) { + t.Errorf("err: got %v, want %v", ev.Err, c.err) + } + if message := ev.Msg != nil; message != c.message { + t.Errorf("message: got %v, want %v", message, c.message) + } + }) + } +} From 7861fd4a374bc70053f02c52f5d1b27f725d5338 Mon Sep 17 00:00:00 2001 From: Bozhidar Batsov Date: Wed, 7 Oct 2026 15:33:35 +0300 Subject: [PATCH 3/4] Add proof proxy for checking clients proof could only check servers. proof proxy sits between a client and a server, forwards every byte as it is and records the frames, and when it's stopped it grades what the client sent against the new client.* rules. The grading rule is turned around for them: a client rule fails only when a server breaks on the request, and links to that server's code. What a client leaves behind (sessions it never closed, input it never sent) only counts when it hung up before the server did, and every connection is taken into account, as a session outlives the connection that created it. --- CONTRIBUTING.md | 6 +- README.md | 27 +- cmd/proof/main.go | 21 +- cmd/proof/proxy.go | 153 ++++++++++ cmd/proof/proxy_test.go | 138 +++++++++ doc/design.md | 46 ++- doc/hacking.md | 29 +- doc/usage.md | 93 +++++- internal/check/rule.go | 13 +- internal/check/rule_test.go | 11 + internal/checks/client.go | 277 ++++++++++++++++++ internal/checks/client_test.go | 251 ++++++++++++++++ internal/checks/fake_test.go | 3 + internal/checks/refs.go | 16 ++ internal/checks/wire.go | 11 +- internal/proxy/proxy.go | 286 +++++++++++++++++++ internal/proxy/proxy_test.go | 504 +++++++++++++++++++++++++++++++++ internal/report/report.go | 2 + internal/report/report_test.go | 15 + nrepl/conn.go | 3 + 20 files changed, 1880 insertions(+), 25 deletions(-) create mode 100644 cmd/proof/proxy.go create mode 100644 cmd/proof/proxy_test.go create mode 100644 internal/checks/client.go create mode 100644 internal/checks/client_test.go create mode 100644 internal/proxy/proxy.go create mode 100644 internal/proxy/proxy_test.go diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index b44c052..6046a25 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -60,9 +60,11 @@ how to add a check. When submitting a pull request: - Make sure every new check is backed by a link to the client code that depends on the behavior (for failures) or to nREPL or the spec (for warnings). See the [grading rule](doc/design.md#how-checks-are-graded) - for details. + for details. For client rules it's the other way around - failures + need a link to the server code that breaks. - Add a quirk to the fake server for every new check, and an entry for - it in `internal/checks/checks_test.go`. + it in `internal/checks/checks_test.go`. Client rules get a quirk in the + scripted client in `internal/checks/client_test.go` instead. - Make sure new and updated checks pass against nREPL itself (`profiles/clojure.toml`). - Run `gofmt -l .`, `go vet ./...` and `go test -race ./...` before diff --git a/README.md b/README.md index 4589174..83ee55d 100644 --- a/README.md +++ b/README.md @@ -8,6 +8,8 @@ proof checks whether an nREPL server will actually work with the clients people use (CIDER, Calva, Conjure, vim-fireplace, REPLy and so on). It talks to the server over a socket like any client would, runs a set of checks against it and tells you what's broken and which clients it breaks. +It can also check the other side of the conversation, i.e. the requests +an nREPL client sends. The [nREPL protocol spec](https://spec.nrepl.org) is still a draft and in a few places it disagrees with what clients actually do. When that @@ -70,10 +72,27 @@ server (or that users will lose data). If your server simply does something differently from the reference nREPL implementation, you'll get a warning instead. +## Checking Clients + +If you're working on a client, `proof proxy` can sit between it and a +server and record everything the two of them say to each other: + +```shell +$ proof proxy -listen 127.0.0.1:7888 profiles/babashka.toml +``` + +Connect your client to port 7888, use it for a while (or run its test +suite against it) and press Ctrl-C when you're done. proof will then +check the requests your client sent - e.g. that every request has an +`id`, that `need-input` gets answered with `stdin` in the right session +and that sessions get closed in the end. Here a failure means that some +server won't work properly with your client, and the report links to the +server code in question. + ## Documentation - [Usage](doc/usage.md) - checking your server, reading the report, - running proof in CI and comparing servers + running proof in CI, comparing servers and checking your client - [Profiles](doc/profiles.md) - all the profile options, the snippets and known failures - [Design](doc/design.md) - the general approach and how checks are graded @@ -87,7 +106,8 @@ get a warning instead. proof is still in its early days. Right now it covers the core of the protocol (`describe`, unknown ops, `eval`, sessions, `stdin` and the wire format), -and `proof list` will show you all the checks. +along with the requests clients send, and `proof list` will show you all +the checks. Here's what's coming next: @@ -96,6 +116,9 @@ Here's what's coming next: clients disconnecting in the middle of an evaluation) - replaying what real clients send (e.g. when CIDER or Calva connect to a server) as client profiles +- a server that misbehaves on purpose (late output, output split into + many messages and so on), so client test suites can check how their + client deals with replies - publishing the compatibility matrix somewhere nicer than a CI job summary diff --git a/cmd/proof/main.go b/cmd/proof/main.go index 4c4eaaa..f1c2594 100644 --- a/cmd/proof/main.go +++ b/cmd/proof/main.go @@ -1,5 +1,5 @@ // Command proof checks an nREPL server's compatibility with the clients -// people actually use. +// people actually use, and what a client sends to a server. package main import ( @@ -25,15 +25,17 @@ const version = "0.1.0-dev" const usage = `proof checks an nREPL server's compatibility with existing clients. Usage: - proof run [flags] PROFILE run the checks against the server a profile describes - proof matrix REPORT... build a Markdown compatibility matrix from JSON reports - proof list list every check and wire rule + proof run [flags] PROFILE run the checks against the server a profile describes + proof proxy [flags] [PROFILE] check what a client sends to a server, by sitting between them + proof matrix REPORT... build a Markdown compatibility matrix from JSON reports + proof list list every check and rule proof version The exit status of run is 0 when everything passed (or failed as the profile expects), 1 when the server failed checks, 2 when proof couldn't start (bad flags or profile, or the server didn't come up), and 3 when some -checks couldn't run at all. +checks couldn't run at all. The same goes for proxy, where 1 means the +client failed rules and 3 means no client sent anything. Run flags: ` @@ -46,6 +48,8 @@ func main() { switch os.Args[1] { case "run": os.Exit(run(os.Args[2:])) + case "proxy": + os.Exit(runProxy(os.Args[2:])) case "matrix": os.Exit(matrix(os.Args[2:])) case "list": @@ -63,6 +67,8 @@ func main() { func printUsage(w io.Writer) { fmt.Fprint(w, usage) runFlags(w).PrintDefaults() + fmt.Fprint(w, "\nProxy flags:\n") + proxyFlags(w, &proxyOptions{}).PrintDefaults() } type options struct { @@ -204,7 +210,8 @@ type entry struct { severity check.Severity } -// catalog lists every check and wire rule. +// catalog lists every check and wire rule, i.e. everything a server +// profile can expect to fail. func catalog() []entry { var all []entry for _, c := range checks.All() { @@ -268,7 +275,7 @@ func filter(all []*check.Check, pattern string) ([]*check.Check, error) { } func list(w io.Writer) { - for _, e := range catalog() { + for _, e := range append(catalog(), ruleEntries(checks.ClientRules())...) { fmt.Fprintf(w, "%-28s %-4s %s\n", e.id, e.severity, e.title) } } diff --git a/cmd/proof/proxy.go b/cmd/proof/proxy.go new file mode 100644 index 0000000..1198469 --- /dev/null +++ b/cmd/proof/proxy.go @@ -0,0 +1,153 @@ +package main + +import ( + "context" + "flag" + "fmt" + "io" + "os" + "os/signal" + "sync" + "syscall" + "time" + + "github.com/nrepl/proof/internal/check" + "github.com/nrepl/proof/internal/checks" + "github.com/nrepl/proof/internal/profile" + "github.com/nrepl/proof/internal/proxy" + "github.com/nrepl/proof/internal/report" + "github.com/nrepl/proof/internal/server" +) + +type proxyOptions struct { + address string + listen string + json string + verbose bool +} + +func proxyFlags(out io.Writer, o *proxyOptions) *flag.FlagSet { + fs := flag.NewFlagSet("proxy", flag.ContinueOnError) + fs.SetOutput(out) + fs.StringVar(&o.address, "address", "", "forward clients to a server already running at `host:port` instead of launching the one the profile describes") + fs.StringVar(&o.listen, "listen", "127.0.0.1:0", "accept clients on `host:port` (port 0 picks a free one)") + fs.StringVar(&o.json, "json", "", "also write a JSON report to `file`") + fs.BoolVar(&o.verbose, "v", false, "show every message the client and the server exchanged") + return fs +} + +// runProxy sits between a client and a server until it's interrupted, and +// then grades everything the client sent. +func runProxy(args []string) int { + // Ctrl-C abandons a server that's still starting, and after that it + // means the client is done. The handler stays for the rest of the run, + // as the server is in its own process group and has to be stopped by + // proof. + ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM) + defer stop() + return proxyUntil(ctx, args, os.Stdout, os.Stderr, nil) +} + +// proxyUntil does the work of runProxy, grading the traffic once ctx is +// done. listening, if not nil, gets the address clients should use. +func proxyUntil(ctx context.Context, args []string, stdout, stderr io.Writer, listening func(addr string)) int { + // The proxy logs to stderr from goroutines of its own. + stderr = &syncWriter{w: stderr} + var o proxyOptions + fs := proxyFlags(stderr, &o) + if err := fs.Parse(args); err != nil { + return 2 + } + if fs.NArg() > 1 || (fs.NArg() == 0 && o.address == "") { + fmt.Fprintln(stderr, "proof proxy: expected a profile or -address") + return 2 + } + upstream, name := o.address, "the server" + var p *profile.Profile + if fs.NArg() == 1 { + var err error + if p, err = profile.Load(fs.Arg(0)); err != nil { + fmt.Fprintln(stderr, "proof:", err) + return 2 + } + name = p.Name + if upstream == "" { + upstream = p.Address + } + } + + var srv *server.Server + if upstream == "" { + fmt.Fprintf(stderr, "Starting %s...\n", p.Name) + var err error + if srv, err = server.Start(ctx, p); err != nil { + if ctx.Err() != nil { + return 130 + } + fmt.Fprintln(stderr, "proof:", err) + return 2 + } + defer srv.Stop() + upstream = srv.Addr + } + px, err := proxy.Listen(o.listen, upstream) + if err != nil { + fmt.Fprintln(stderr, "proof:", err) + return 2 + } + px.Logf = func(format string, args ...any) { + fmt.Fprintf(stderr, format+"\n", args...) + } + go px.Serve() + started := time.Now() + fmt.Fprintf(stderr, "Forwarding %s to %s. Connect your client to %s and press Ctrl-C when it's done.\n", + px.Addr(), upstream, px.Addr()) + if listening != nil { + listening(px.Addr()) + } + + <-ctx.Done() + fmt.Fprintln(stderr) + traffic := px.Stop(time.Second) + if len(traffic) == 0 { + fmt.Fprintln(stderr, "proof: no client sent anything to the server, so there's nothing to check") + showDeath(stderr, srv) + return 3 + } + r := report.Run{ + Proof: version, + Server: "client traffic to " + name, + Address: upstream, + Started: started, + Results: check.Grade(checks.ClientRules(), traffic), + } + report.Text(stdout, r, o.verbose) + if o.verbose { + for _, tr := range traffic { + fmt.Fprintf(stdout, "\n%s:\n", tr.Label) + report.Transcript(stdout, tr.Events, " ") + } + } + showDeath(stdout, srv) + if o.json != "" { + if err := writeJSON(o.json, r); err != nil { + fmt.Fprintln(stderr, "proof:", err) + return 2 + } + } + if r.Counts()[check.Failed] > 0 { + return 1 + } + return 0 +} + +type syncWriter struct { + mu sync.Mutex + w io.Writer +} + +func (s *syncWriter) Write(p []byte) (int, error) { + s.mu.Lock() + defer s.mu.Unlock() + return s.w.Write(p) +} diff --git a/cmd/proof/proxy_test.go b/cmd/proof/proxy_test.go new file mode 100644 index 0000000..94b4e00 --- /dev/null +++ b/cmd/proof/proxy_test.go @@ -0,0 +1,138 @@ +package main + +import ( + "bufio" + "bytes" + "context" + "io" + "net" + "os" + "path/filepath" + "strings" + "testing" + "time" + + "github.com/nrepl/proof/bencode" +) + +// doneServer answers every request with done. +func doneServer(t *testing.T) string { + t.Helper() + ln, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { ln.Close() }) + go func() { + for { + c, err := ln.Accept() + if err != nil { + return + } + go func() { + defer c.Close() + dec := bencode.NewDecoder(bufio.NewReader(c)) + for { + v, err := dec.Decode() + if err != nil { + return + } + reply := map[string]any{"status": []any{"done"}} + if m, ok := v.Data.(map[string]any); ok && m["id"] != nil { + reply["id"] = m["id"] + } + b, _ := bencode.Marshal(reply) + c.Write(b) + } + }() + } + }() + return ln.Addr().String() +} + +// proxyRun runs proof proxy with a client that sends the given frames and +// hangs up, and returns the exit status and output. +func proxyRun(t *testing.T, frames []string, args ...string) (int, string, string) { + t.Helper() + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + client := func(addr string) { + defer cancel() + if len(frames) == 0 { + return + } + c, err := net.Dial("tcp", addr) + if err != nil { + t.Error(err) + return + } + defer c.Close() + for _, f := range frames { + c.Write([]byte(f)) + } + c.(*net.TCPConn).CloseWrite() + c.SetReadDeadline(time.Now().Add(2 * time.Second)) + io.Copy(io.Discard, c) + } + var stdout, stderr bytes.Buffer + args = append([]string{"-address", doneServer(t)}, args...) + code := proxyUntil(ctx, args, &stdout, &stderr, client) + return code, stdout.String(), stderr.String() +} + +func TestProxyExitCodes(t *testing.T) { + cases := []struct { + name string + frames []string + code int + output string + }{ + {"well-behaved client", []string{"d2:id1:12:op8:describee"}, 0, "client.id"}, + {"request without an id", []string{"d2:op8:describee"}, 1, "a request without an id"}, + {"no client", nil, 3, "nothing to check"}, + } + for _, c := range cases { + t.Run(c.name, func(t *testing.T) { + code, stdout, stderr := proxyRun(t, c.frames) + if code != c.code { + t.Errorf("exit status %d, want %d\nstdout:\n%s\nstderr:\n%s", code, c.code, stdout, stderr) + } + if !strings.Contains(stdout+stderr, c.output) { + t.Errorf("output doesn't mention %q\nstdout:\n%s\nstderr:\n%s", c.output, stdout, stderr) + } + }) + } +} + +func TestProxyWritesJSONAndTranscripts(t *testing.T) { + path := filepath.Join(t.TempDir(), "client.json") + code, stdout, _ := proxyRun(t, []string{"d2:id1:12:op8:describee"}, "-v", "-json", path) + if code != 0 { + t.Fatalf("exit status %d:\n%s", code, stdout) + } + if !strings.Contains(stdout, "connection 1:") || !strings.Contains(stdout, "closed the connection") { + t.Errorf("no transcript in the output:\n%s", stdout) + } + b, err := os.ReadFile(path) + if err != nil { + t.Fatal(err) + } + if !strings.Contains(string(b), `"client.need-input"`) { + t.Errorf("JSON report has no client rules:\n%s", b) + } +} + +func TestProxyNeedsAServer(t *testing.T) { + var stderr bytes.Buffer + if code := proxyUntil(context.Background(), nil, io.Discard, &stderr, nil); code != 2 { + t.Errorf("exit status %d, want 2", code) + } +} + +func TestListShowsClientRules(t *testing.T) { + var buf bytes.Buffer + list(&buf) + if !strings.Contains(buf.String(), "client.need-input") || !strings.Contains(buf.String(), "wire.dict") { + t.Errorf("list is missing rules:\n%s", buf.String()) + } +} diff --git a/doc/design.md b/doc/design.md index 344ea02..d3beb12 100644 --- a/doc/design.md +++ b/doc/design.md @@ -20,6 +20,9 @@ whom. When you run the same checks against many servers you also get a compatibility matrix, which shows where the different implementations agree, where they don't and where the spec needs some work. +The same knowledge cuts both ways, so proof can also check what a client +sends to a server (see [Checking Clients](#checking-clients) below). + ## Compatibility, Not Conformance The [nREPL protocol spec](https://spec.nrepl.org) is still a draft. It @@ -131,6 +134,37 @@ and status messages in many legitimate ways. (HTTP/2's h2spec, for instance, has open bug reports about false failures caused by unrelated frames arriving between the ones it expected.) +## Checking Clients + +`proof proxy` sits between a client and a server, passes everything +along as is and records it on the way. Once it's stopped, it grades +the requests of the client against the client rules (`client.*`), which +work just like the wire checks, only in the other direction. + +The [grading rule](#how-checks-are-graded) is the same as for servers, +only turned around. A client rule fails only when some server breaks (or +users lose data), and it links to the server code in question. For +instance, `client.field-types` fails when `line` isn't an integer, +because that kills the session's thread in nREPL +([nrepl#477](https://github.com/nrepl/nrepl/issues/477)). A warning means +that the client does something the spec or the reference implementation +doesn't expect, but that servers tolerate. Before a rule was added, the +mistake it catches was sent to nREPL, Babashka, Basilisp and jank to see +how they react. + +As a proxy can only see the wire, proof checks what a client sends and +not what it does with the replies. Whether a client copes with output +that arrives after `done`, or with output split into many messages, is a +different problem, which needs a server that misbehaves on purpose (see +[Future Plans](#future-plans)). + +Some rules are about what a client leaves behind - sessions that were +never closed and `need-input` that was never answered. They apply only +to connections the client closed itself, before the server did. If proof +is stopped while a client is still connected, the client might simply +not have gotten to them yet, and if the server hangs up first, it never +got the chance. + ## Expected Failures To be useful in the CI of a server, proof has to be able to pass while @@ -172,9 +206,10 @@ Here's how the codebase is organized: ``` cmd/proof the command-line interface internal/report text and JSON reports, the compatibility matrix -internal/checks the checks, the wire checks and a fake server for testing them +internal/checks the checks, the wire checks, the client rules and a fake server for testing them internal/check running and grading checks, expected failures internal/server starting servers +internal/proxy forwarding and recording the traffic between a client and a server internal/profile loading profiles nrepl a client that records all messages bencode a strict bencode implementation @@ -213,7 +248,8 @@ to have a single test suite that every server can be checked against. ## Future Plans At this point proof covers the core of the protocol (`describe`, unknown -ops, sessions, `eval`, `stdin` and the wire format). Here's what's planned next: +ops, sessions, `eval`, `stdin` and the wire format) and the requests of +clients. Here's what's planned next: - checks for `interrupt`, which every interactive client relies on - checks for `completions`, `lookup` and `load-file` (for servers that @@ -222,7 +258,11 @@ ops, sessions, `eval`, `stdin` and the wire format). Here's what's planned next: disconnecting in the middle of an evaluation) - client profiles that replay what specific clients send (e.g. when CIDER or Calva connect to a server), so a report can tell you - directly whether CIDER will work with your server + directly whether CIDER will work with your server (`proof proxy` + already sees this traffic, it just doesn't save it yet) +- a server that misbehaves on purpose (late output, output split into + many messages, unusual status values), for client test suites to run + against - more servers in the compatibility matrix and a proper home for the matrix itself - incorporating [Spec Changes](spec-changes.md) into the spec, so that diff --git a/doc/hacking.md b/doc/hacking.md index b61a3f2..0129d37 100644 --- a/doc/hacking.md +++ b/doc/hacking.md @@ -45,7 +45,8 @@ $ bin/proof run profiles/clojure.toml | `internal/profile` | Loading and validating profiles. | | `internal/server` | Starting servers and figuring out their ports. | | `internal/check` | The checks framework (`Check`, `T`, `Rule`), grading and expected failures. It doesn't know anything about specific ops. | -| `internal/checks` | The checks (`describe.go`, `op.go`, `session.go` and `eval.go`), the wire checks (`wire.go`), the links to client code (`refs.go`) and the fake server used to test all of them (`fake_test.go`). | +| `internal/checks` | The checks (`describe.go`, `op.go`, `session.go` and `eval.go`), the wire checks (`wire.go`), the client rules (`client.go`), the links to client and server code (`refs.go`), the fake server used to test all of them (`fake_test.go`) and a scripted client for testing the client rules (`client_test.go`). | +| `internal/proxy` | Forwarding the traffic between a client and a server and recording it, for `proof proxy`. | | `internal/report` | Text and JSON reports and the compatibility matrix. | | `profiles` | The profiles for the servers in the compatibility matrix. | | `doc/spec-changes.md` | All the gaps and disagreements found in the draft spec. | @@ -66,6 +67,10 @@ be configured to misbehave in many different ways (see `quirks`), and In other words - every check needs a quirk that makes it fail. Otherwise we have no evidence that the check can fail at all. +The client rules are tested the same way. `client_test.go` has a scripted +client that talks to the fake server through the proxy and can be told to +make one mistake at a time (see `clientQuirks`). + Before submitting any changes make sure the code is formatted properly and the tests pass with the race detector enabled: @@ -193,6 +198,26 @@ There are a few helpers for going over the messages of a connection: Just like the regular checks, every wire check needs a quirk and an entry in the table in `checks_test.go`. +## Adding a Client Rule + +The client rules live in `client.go`. They are wire checks for the other +direction - their `Inspect` function gets the messages of one connection +recorded by `proof proxy`, where the requests of the client are +`nrepl.Sent` and the replies of the server are `nrepl.Received`. +`eachRequest` goes over the requests, and the helpers of the wire checks +work here as well. Rules about sessions use `InspectAll` instead, which +gets every connection at once, as a client can close a session (or send +it input) from a different connection than the one that created it. + +For clients the [grading rule](design.md#checking-clients) is turned +around, so a client rule that fails needs a link to the server code that +breaks. Before adding one, send the request in question to a few real +servers and see how they react. A small script that writes the request +to a socket and prints the replies is all you need for that. + +Every client rule needs a quirk in `clientQuirks` and an entry in the +table in `TestClientRulesCatchMistakes` (both in `client_test.go`). + ## Adding a Server To add a server to the compatibility matrix: @@ -211,7 +236,7 @@ To add a server to the compatibility matrix: ## Links to Client Code -The links to the code of clients and nREPL live in `refs.go`. Each +The links to the code of clients and servers live in `refs.go`. Each project has a base URL that's pinned to a specific commit, and each link combines a base with a path and a range of lines: diff --git a/doc/usage.md b/doc/usage.md index 9821427..d8c931e 100644 --- a/doc/usage.md +++ b/doc/usage.md @@ -2,8 +2,8 @@ This section of the documentation covers everything you need to check an nREPL server with proof, from installing proof to running it in your -server's CI. The details of the profile format are covered separately in -[Profiles](profiles.md). +server's CI, and how to check an nREPL client with it. The details of the +profile format are covered separately in [Profiles](profiles.md). ## Installation @@ -203,6 +203,95 @@ you'll probably want to put the reference implementation first. > Compatibility workflow on the > [Actions tab](https://github.com/nrepl/proof/actions). +## Checking Your Client + +If you're working on an nREPL client, proof can check the requests it +sends. `proof proxy` starts a server (or uses one that's already +running) and forwards everything between your client and the server, +recording every message on the way: + +```shell +$ proof proxy -listen 127.0.0.1:7888 profiles/clojure.toml +Starting Clojure (nrepl/nrepl 1.7.0)... +Forwarding 127.0.0.1:7888 to localhost:53613. Connect your client to 127.0.0.1:7888 and press Ctrl-C when it's done. +``` + +Connect your client to this port and use it as you normally would - +evaluate some code, read some input, interrupt something. When you're +done, disconnect the client and press Ctrl-C. proof will then check +everything the client sent: + +``` +client + PASS client.id Every request has an id + FAIL client.need-input need-input is answered with stdin in the same session + need-input went unanswered (during connection 1): {id "2", session "dd88...", status ["need-input"]} + why: Code reading input waits until it gets some, so an unanswered need-input leaves the eval, and the session it runs in, hanging forever. + see: nREPL hands stdin to the reader of the request's session https://github.com/nrepl/nrepl/blob/edf294a7.../src/clojure/nrepl/middleware/session.clj#L380-L388 + WARN client.close Sessions are closed before disconnecting + a session was never closed (during connection 1): {id "1", new-session "dd88...", session "d5b1...", status ["done"]} + ... +``` + +The verdicts mean the same things as for servers, only the other way +around. A failure means that some server won't work properly with your +client (or that users will lose data), and the `see` lines link to the +server code in question. A warning means that your client does something +servers tolerate, but that they shouldn't have to. + +Keep in mind that proof can only see what goes over the wire. It checks +the requests your client sends, but not what your client does with the +replies. It also checks only what your client actually did - if you never +evaluate code that reads input, nobody will know how your client handles +`need-input`. And the checks about what a client leaves behind (sessions +that were never closed and input that was never sent) apply only to +connections your client closed itself while the server was still around. +A client that's still connected when you press Ctrl-C might simply not +have gotten to them yet, and one whose server went away first never got +the chance. + +It's a good idea to try your client with a few servers, as they don't +all support the same ops. Any profile from the [profiles](../profiles) +folder will do, and with `-address` proof will forward your client to a +server that's already running: + +```shell +$ proof proxy -address localhost:1667 +``` + +Here are the options supported by `proof proxy`: + +| Option | Description | +|---|---| +| `-address host:port` | Forward the client to a running server instead of starting one. | +| `-listen host:port` | Accept the client on this address. The default is `127.0.0.1:0`, which picks a free port. | +| `-v` | Show every message exchanged between the client and the server. | +| `-json file` | Write a JSON report as well. | + +The exit codes are the same as for `proof run`, except that 1 means that +the client failed some checks and 3 means that no client sent anything. + +You can also run your client's test suite through proof in CI. Start +the proxy in the background, wait for it to accept connections, run the +tests against it and stop it with `SIGINT`: + +```shell +proof proxy -listen 127.0.0.1:7888 profiles/babashka.toml & +proxy=$! +until nc -z 127.0.0.1 7888; do + kill -0 $proxy || exit 2 + sleep 1 +done +# run your tests against port 7888 here +kill -INT $proxy +wait $proxy +``` + +`wait` returns the exit code of proof, so the step fails when your +client fails some checks. The `kill -0` makes sure the step doesn't wait +forever if proof can't start the server, and the connections `nc` makes +don't count, as they don't send anything. + ## Troubleshooting This section lists the most common problems you may encounter while diff --git a/internal/check/rule.go b/internal/check/rule.go index 5284840..df237dd 100644 --- a/internal/check/rule.go +++ b/internal/check/rule.go @@ -25,6 +25,11 @@ type Rule struct { Refs []Ref // Inspect looks at one connection's events and reports each problem. Inspect func(events []nrepl.Event, report Reporter) + // InspectAll is used instead of Inspect by rules that have to see + // every connection at once, e.g. because sessions outlive the + // connection that created them. It reports each problem with the + // Reporter for the connection it was on. + InspectAll func(traffic []Traffic, reporter func(Traffic) Reporter) } // Reporter takes a problem and an example of it. Identical problems are @@ -64,8 +69,12 @@ func (r *Rule) grade(traffic []Traffic) Result { problems = append(problems, p) } } - for _, tr := range traffic { - r.Inspect(tr.Events, reporter(tr)) + if r.InspectAll != nil { + r.InspectAll(traffic, reporter) + } else { + for _, tr := range traffic { + r.Inspect(tr.Events, reporter(tr)) + } } for i, p := range problems { if i == maxRuleDetails { diff --git a/internal/check/rule_test.go b/internal/check/rule_test.go index 1ac5923..4237eb6 100644 --- a/internal/check/rule_test.go +++ b/internal/check/rule_test.go @@ -1,6 +1,7 @@ package check import ( + "fmt" "strings" "testing" @@ -37,3 +38,13 @@ func TestGradePassesCleanTraffic(t *testing.T) { t.Errorf("got %s %v", res.Verdict, res.Details) } } + +func TestGradeSeesEveryConnectionAtOnce(t *testing.T) { + rule := &Rule{ID: "client.x", Severity: Warn, InspectAll: func(traffic []Traffic, reporter func(Traffic) Reporter) { + reporter(traffic[len(traffic)-1])(fmt.Sprintf("%d connections", len(traffic)), "") + }} + res := rule.grade([]Traffic{{Label: "connection 1"}, {Label: "connection 2"}}) + if res.Verdict != Warned || len(res.Details) != 1 || res.Details[0] != "2 connections (during connection 2)" { + t.Errorf("got %s %v", res.Verdict, res.Details) + } +} diff --git a/internal/checks/client.go b/internal/checks/client.go new file mode 100644 index 0000000..82bf46c --- /dev/null +++ b/internal/checks/client.go @@ -0,0 +1,277 @@ +package checks + +import ( + "time" + + "github.com/nrepl/proof/internal/check" + "github.com/nrepl/proof/nrepl" +) + +// Request fields that servers choke on when they're of the wrong type. +var ( + requestStringFields = []string{"op", "session", "code", "ns", "stdin"} + requestIntFields = []string{"line", "column"} +) + +// ClientRules returns the rules for what a client sends, graded against +// the traffic recorded by proof proxy. Here a failure means that some +// server won't work properly with the client. +func ClientRules() []*check.Rule { + return []*check.Rule{ + { + ID: "client.bencode", + Title: "Every frame is valid bencode", + Severity: check.Fail, + Why: "Servers can't read past a broken frame: nREPL closes the connection and babashka.nrepl stops answering on it.", + Refs: []check.Ref{nreplConnLoop, bbSessionLoop, specProtocol}, + Inspect: eachFrame(nrepl.Sent, badFrame), + }, + { + ID: "client.dict", + Title: "Every request is a dict", + Severity: check.Fail, + Why: "nREPL closes the connection on a request that isn't a dict, and babashka.nrepl stops answering on it.", + Refs: []check.Ref{nreplConnLoop, bbSessionLoop, specProtocol}, + Inspect: eachFrame(nrepl.Sent, notDict), + }, + { + ID: "client.canonical", + Title: "Frames use canonical bencode", + Severity: check.Warn, + Why: "The servers we know of accept unsorted keys and leading zeros, but it's invalid bencode and a stricter decoder would reject it.", + Refs: []check.Ref{specProtocol}, + Inspect: eachFrame(nrepl.Sent, nonCanonical), + }, + { + ID: "client.id", + Title: "Every request has an id", + Severity: check.Fail, + Why: "Replies to a request without an id can't be told apart from the rest: nREPL sends them without one, babashka.nrepl with \"unknown\" and Basilisp with \"\".", + Refs: []check.Ref{nreplReplyID, bbUnknownID, basilispReplyID, specProtocol}, + Inspect: eachRequest(func(m nrepl.Message, report check.Reporter) { + if !m.Has("id") { + report("a request without an id", m.String()) + } + }), + }, + { + ID: "client.active-id", + Title: "An id isn't reused while its request is active", + Severity: check.Fail, + Why: "Replies are matched to requests by id, so two active requests with the same id get each other's replies (e.g. an eval ends at the done meant for a stdin request that reused its id).", + Refs: []check.Ref{specProtocol}, + Inspect: reusedIDs, + }, + { + ID: "client.field-types", + Title: "Request fields have the right types", + Severity: check.Fail, + Why: "Servers break on fields of the wrong type: a line, column or stdin nREPL doesn't expect kills the session's thread, and nREPL and Basilisp never answer an eval whose ns isn't a string.", + Refs: []check.Ref{nreplLineColumn, issue("nrepl/nrepl", 477), nreplEvalNs, basilispEvalNs, basilispOp}, + Inspect: eachRequest(func(m nrepl.Message, report check.Reporter) { + wrongTypes[string](m, requestStringFields, report) + wrongTypes[int64](m, requestIntFields, report) + }), + }, + { + ID: "client.required-fields", + Title: "Requests carry the fields their op needs", + Severity: check.Fail, + Why: "Servers can't do what such requests ask: an eval without code evaluates nothing, and stdin or interrupt without a session can't reach the eval they're meant for.", + Refs: []check.Ref{specProtocol, nreplNoCode, nreplStdinSession, nreplInterruptNoSes}, + Inspect: eachRequest(func(m nrepl.Message, report check.Reporter) { + if !m.Has("op") { + report("a request without an op", m.String()) + } + switch m.Str("op") { + case "eval": + if !m.Has("code") { + report("an eval request without code", m.String()) + } + case "stdin": + if !m.Has("stdin") { + report("a stdin request without stdin", m.String()) + } + if !m.Has("session") { + report("a stdin request without a session", m.String()) + } + case "interrupt": + if !m.Has("session") { + report("an interrupt request without a session", m.String()) + } + } + }), + }, + { + ID: "client.need-input", + Title: "need-input is answered with stdin in the same session", + Severity: check.Fail, + Why: "Code reading input waits until it gets some, so an unanswered need-input leaves the eval, and the session it runs in, hanging forever.", + Refs: []check.Ref{nreplStdinSession, specStdin}, + InspectAll: unansweredInput, + }, + { + ID: "client.close", + Title: "Sessions are closed before disconnecting", + Severity: check.Warn, + Why: "Sessions outlive connections, so nREPL keeps every session a client doesn't close (along with its thread) until the server stops.", + Refs: []check.Ref{nreplSessions, specClose}, + InspectAll: unclosedSessions, + }, + { + ID: "client.unknown-op", + Title: "Requests use ops the server supports", + Severity: check.Warn, + Why: "A request for an op the server doesn't support only gets unknown-op back. describe lists the supported ops, and CIDER checks it before using one.", + Refs: []check.Ref{ciderOpSupported, specDescribe}, + Inspect: eachReply(func(r reply, report check.Reporter) { + if !r.Msg.HasStatus("unknown-op") || r.Req == nil { + return + } + // Requests without a proper op are client.required-fields' + // and client.field-types' business. + if op := r.Req.Str("op"); op != "" { + report(op+" isn't supported by the server", r.Req.String()) + } + }), + }, + } +} + +func eachRequest(f func(nrepl.Message, check.Reporter)) func([]nrepl.Event, check.Reporter) { + return eachMessageIn(nrepl.Sent, f) +} + +// hungUp reports whether the client closed the connection while the +// server was still there, rather than after the server hung up (or proof +// cut it off). What a client leaves behind (sessions, evals waiting for +// input) only counts against it then. That includes replies that came +// after it left, as it didn't wait for them. +func hungUp(events []nrepl.Event) bool { + for _, ev := range events { + if ev.Closed { + return ev.Dir == nrepl.Sent + } + } + return false +} + +func reusedIDs(events []nrepl.Event, report check.Reporter) { + active := map[string]bool{} + for _, ev := range events { + key, ok := idKey(ev.Msg) + if !ok { + continue + } + switch { + case ev.Dir == nrepl.Received && ev.Msg.HasStatus("done"): + delete(active, key) + case ev.Dir == nrepl.Sent: + if active[key] { + report("an id was reused while its request was still active", ev.Msg.String()) + } + active[key] = true + } + } +} + +// eachSessionRequest calls f for every request in a session, on any +// connection, since sessions outlive the connection that created them. +func eachSessionRequest(traffic []check.Traffic, f func(ev nrepl.Event, session string)) { + for _, tr := range traffic { + for _, ev := range tr.Events { + if ev.Dir == nrepl.Sent && ev.Msg != nil && ev.Msg.Str("session") != "" { + f(ev, ev.Msg.Str("session")) + } + } + } +} + +func unansweredInput(traffic []check.Traffic, reporter func(check.Traffic) check.Reporter) { + // Sending input answers a need-input, and interrupting the eval or + // closing the session gives up on it. Any of them can come from any + // connection. An interrupt with an interrupt-id only stops the eval it + // names, and the rest cover the whole session. + type eval struct{ session, id string } + bySession, byEval := map[string]time.Time{}, map[eval]time.Time{} + eachSessionRequest(traffic, func(ev nrepl.Event, session string) { + switch op := ev.Msg.Str("op"); { + case op == "interrupt" && ev.Msg.Has("interrupt-id"): + e := eval{session, valueKey(ev.Msg["interrupt-id"])} + byEval[e] = latest(byEval[e], ev.Time) + case op == "stdin", op == "interrupt", op == "close": + bySession[session] = latest(bySession[session], ev.Time) + } + }) + answered := func(session string, w nrepl.Event) bool { + id, _ := idKey(w.Msg) + return !bySession[session].Before(w.Time) || !byEval[eval{session, id}].Before(w.Time) + } + for _, tr := range traffic { + if !hungUp(tr.Events) { + continue + } + requests := map[string]nrepl.Message{} + // waiting maps sessions to the need-input asking for their input. + waiting := map[string]nrepl.Event{} + var order []string + for _, ev := range tr.Events { + m := ev.Msg + id, ok := idKey(m) + if !ok { + continue + } + switch { + case ev.Dir == nrepl.Sent: + requests[id] = m + case m.HasStatus("need-input"): + session := m.Str("session") + if session == "" { + session = requests[id].Str("session") + } + if _, ok := waiting[session]; !ok { + order = append(order, session) + } + waiting[session] = ev + case m.HasStatus("done"): + for session, w := range waiting { + if key, _ := idKey(w.Msg); key == id { + delete(waiting, session) + } + } + } + } + for _, session := range order { + if w, ok := waiting[session]; ok && !answered(session, w) { + reporter(tr)("need-input went unanswered", w.Msg.String()) + delete(waiting, session) + } + } + } +} + +func latest(a, b time.Time) time.Time { + if b.After(a) { + return b + } + return a +} + +func unclosedSessions(traffic []check.Traffic, reporter func(check.Traffic) check.Reporter) { + closed := map[string]bool{} + eachSessionRequest(traffic, func(ev nrepl.Event, session string) { + if ev.Msg.Str("op") == "close" { + closed[session] = true + } + }) + for _, tr := range traffic { + if !hungUp(tr.Events) { + continue + } + eachReply(func(r reply, report check.Reporter) { + if s := r.Msg.Str("new-session"); r.Req.Str("op") == "clone" && s != "" && !closed[s] { + report("a session was never closed", r.Msg.String()) + } + })(tr.Events, reporter(tr)) + } +} diff --git a/internal/checks/client_test.go b/internal/checks/client_test.go new file mode 100644 index 0000000..6713341 --- /dev/null +++ b/internal/checks/client_test.go @@ -0,0 +1,251 @@ +package checks + +import ( + "io" + "net" + "testing" + "time" + + "github.com/nrepl/proof/bencode" + "github.com/nrepl/proof/internal/check" + "github.com/nrepl/proof/internal/proxy" + "github.com/nrepl/proof/nrepl" +) + +// clientQuirks switch on one mistake each in the scripted client, so the +// tests can confirm every client rule catches what it claims to and +// nothing else. +type clientQuirks struct { + badFrame bool // sends something that isn't bencode + notDict bool // sends a list instead of a dict + unsortedKeys bool + noID bool + reusedID bool // answers need-input with the id of the eval asking for it + stringLine bool // line is a string + noCode bool // an eval without code + stdinNoSession bool + ignoreInput bool // never sends the input an eval waits for + leaveOpen bool // never closes its session + closeElsewhere bool // closes its session from another connection + unknownOp bool + // stayConnected leaves the client connected when the proxy stops. + stayConnected bool +} + +// runClient puts a scripted client session through the proxy to the fake +// server and grades what the client sent. +func runClient(t *testing.T, q clientQuirks) map[string]check.Result { + t.Helper() + px, err := proxy.Listen("127.0.0.1:0", startFake(t, quirks{})) + if err != nil { + t.Fatal(err) + } + go px.Serve() + t.Cleanup(func() { px.Stop(0) }) + + dial := func() *nrepl.Conn { + t.Helper() + c, err := nrepl.Dial(px.Addr(), time.Second) + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { c.Close() }) + return c + } + c := dial() + request := func(m nrepl.Message) nrepl.Response { + t.Helper() + resp, err := c.Request(m, time.Second) + if err != nil { + t.Fatalf("%s: %v", m, err) + } + return resp + } + request(nrepl.Message{"op": "describe"}) + session := nrepl.Message{"session": request(nrepl.Message{"op": "clone"}).Str("new-session")} + + eval := nrepl.Message{"op": "eval", "code": "value", "line": 1, "column": 1} + if q.stringLine { + eval["line"] = "1" + } + if q.noCode { + delete(eval, "code") + } + evalID := request(session.With(eval)).Str("id") + + id, err := c.Send(session.With(nrepl.Message{"op": "eval", "code": "read"})) + if err != nil { + t.Fatal(err) + } + if _, err := c.WaitFor(needInput(id), time.Second); err != nil { + t.Fatal(err) + } + if !q.ignoreInput { + stdin := nrepl.Message{"op": "stdin", "stdin": "proof\n"} + if !q.stdinNoSession { + stdin = session.With(stdin) + } + if q.reusedID { + stdin["id"] = id + } + request(stdin) + } + // An interrupt for an eval that's long done, which doesn't give up on + // any input. + request(session.With(nrepl.Message{"op": "interrupt", "interrupt-id": evalID})) + if q.unknownOp { + request(nrepl.Message{"op": "proof-unknown"}) + } + closing := session.With(nrepl.Message{"op": "close"}) + if !q.leaveOpen && !q.stayConnected && !q.closeElsewhere { + request(closing) + } + if q.closeElsewhere { + c.Close() + c = dial() + request(closing) + c.Close() + } + + // Frames nrepl.Conn won't send go over connections of their own. + var frames [][]byte + if q.badFrame { + frames = append(frames, []byte("hello\n")) + } + if q.notDict { + frames = append(frames, []byte("l8:describee")) + } + if q.unsortedKeys { + frames = append(frames, []byte("d2:op8:describe2:id1:xe")) + } + if q.noID { + b, _ := bencode.Marshal(map[string]any{"op": "describe"}) + frames = append(frames, b) + } + for _, f := range frames { + nc, err := net.Dial("tcp", px.Addr()) + if err != nil { + t.Fatal(err) + } + nc.Write(f) + // Hang up, and wait for the proxy to do the same, so the exchange + // is over by the time the proxy stops. + nc.(*net.TCPConn).CloseWrite() + nc.SetReadDeadline(time.Now().Add(time.Second)) + io.Copy(io.Discard, nc) + nc.Close() + } + + grace := time.Second + if q.stayConnected { + grace = 50 * time.Millisecond + } else { + c.Close() + } + traffic := px.Stop(grace) + want := 1 + len(frames) + if q.closeElsewhere { + want++ + } + if len(traffic) != want { + t.Fatalf("got %d transcripts, want %d", len(traffic), want) + } + results := map[string]check.Result{} + for _, r := range check.Grade(ClientRules(), traffic) { + results[r.ID] = r + } + return results +} + +func TestWellBehavedClientPassesEverything(t *testing.T) { + checkVerdicts(t, runClient(t, clientQuirks{}), nil) +} + +// Each mistake must produce exactly the listed verdicts, and every other +// rule must still pass. +func TestClientRulesCatchMistakes(t *testing.T) { + F, W := check.Failed, check.Warned + cases := []struct { + name string + q clientQuirks + want map[string]check.Verdict + }{ + {"broken frame", clientQuirks{badFrame: true}, map[string]check.Verdict{"client.bencode": F}}, + {"list instead of a dict", clientQuirks{notDict: true}, map[string]check.Verdict{"client.dict": F}}, + {"unsorted keys", clientQuirks{unsortedKeys: true}, map[string]check.Verdict{"client.canonical": W}}, + {"no id", clientQuirks{noID: true}, map[string]check.Verdict{"client.id": F}}, + {"id reused by stdin", clientQuirks{reusedID: true}, map[string]check.Verdict{"client.active-id": F}}, + {"line is a string", clientQuirks{stringLine: true}, map[string]check.Verdict{"client.field-types": F}}, + {"eval without code", clientQuirks{noCode: true}, map[string]check.Verdict{"client.required-fields": F}}, + {"stdin without a session", clientQuirks{stdinNoSession: true, leaveOpen: true}, map[string]check.Verdict{ + "client.required-fields": F, "client.need-input": F, "client.close": W}}, + {"input never sent", clientQuirks{ignoreInput: true, leaveOpen: true}, map[string]check.Verdict{ + "client.need-input": F, "client.close": W}}, + {"session closed instead of sending input", clientQuirks{ignoreInput: true}, nil}, + {"session left open", clientQuirks{leaveOpen: true}, map[string]check.Verdict{"client.close": W}}, + {"session closed from another connection", clientQuirks{closeElsewhere: true}, nil}, + {"unsupported op", clientQuirks{unknownOp: true}, map[string]check.Verdict{"client.unknown-op": W}}, + } + for _, c := range cases { + t.Run(c.name, func(t *testing.T) { + t.Parallel() + checkVerdicts(t, runClient(t, c.q), c.want) + }) + } +} + +// A client that's still connected when proof stops hasn't had the chance +// to answer need-input or close its sessions, so it isn't judged on them. +func TestOpenConnectionsAreNotJudgedOnWhatTheyLeaveBehind(t *testing.T) { + results := runClient(t, clientQuirks{ignoreInput: true, stayConnected: true}) + for _, id := range []string{"client.need-input", "client.close"} { + if v := results[id].Verdict; v != check.Pass { + t.Errorf("%s: got %s %v, want pass", id, v, results[id].Details) + } + } +} + +// What a client leaves behind only counts when it left first. Replies +// that came after that still count, as it didn't wait for them. +func TestLeftoversCountOnlyWhenTheClientLeftFirst(t *testing.T) { + clone := nrepl.Event{Dir: nrepl.Sent, Msg: nrepl.Message{"id": "1", "op": "clone"}} + cloned := nrepl.Event{Dir: nrepl.Received, Msg: nrepl.Message{"id": "1", "new-session": "s", "status": []any{"done"}}} + eval := nrepl.Event{Dir: nrepl.Sent, Msg: nrepl.Message{"id": "2", "op": "eval", "code": "(read-line)", "session": "s"}} + needInput := nrepl.Event{Dir: nrepl.Received, Msg: nrepl.Message{"id": "2", "session": "s", "status": []any{"need-input"}}} + interrupt := nrepl.Event{Dir: nrepl.Sent, Msg: nrepl.Message{"id": "3", "op": "interrupt", "session": "s", "interrupt-id": "2"}} + otherInterrupt := nrepl.Event{Dir: nrepl.Sent, Msg: nrepl.Message{"id": "4", "op": "interrupt", "session": "s", "interrupt-id": "1"}} + interrupted := nrepl.Event{Dir: nrepl.Received, Msg: nrepl.Message{"id": "2", "session": "s", "status": []any{"done", "interrupted"}}} + clientGone := nrepl.Event{Dir: nrepl.Sent, Closed: true} + serverGone := nrepl.Event{Dir: nrepl.Received, Closed: true} + cases := []struct { + name string + events []nrepl.Event + rule string + want check.Verdict + }{ + {"session, client first", []nrepl.Event{clone, cloned, clientGone, serverGone}, "client.close", check.Warned}, + {"session, server first", []nrepl.Event{clone, cloned, serverGone, clientGone}, "client.close", check.Pass}, + {"session the client didn't wait for", []nrepl.Event{clone, clientGone, cloned, serverGone}, "client.close", check.Warned}, + {"input, client first", []nrepl.Event{eval, needInput, clientGone, serverGone}, "client.need-input", check.Failed}, + {"input, server first", []nrepl.Event{eval, needInput, serverGone, clientGone}, "client.need-input", check.Pass}, + {"input the client didn't wait for", []nrepl.Event{eval, clientGone, needInput, serverGone}, "client.need-input", check.Failed}, + {"interrupted before leaving", []nrepl.Event{eval, needInput, interrupt, clientGone, interrupted, serverGone}, "client.need-input", check.Pass}, + {"interrupted, then gone before the done", []nrepl.Event{eval, needInput, interrupt, clientGone, serverGone}, "client.need-input", check.Pass}, + {"some other eval interrupted", []nrepl.Event{eval, needInput, otherInterrupt, clientGone, serverGone}, "client.need-input", check.Failed}, + } + for _, c := range cases { + t.Run(c.name, func(t *testing.T) { + // Input is matched up with need-input by time. + events := make([]nrepl.Event, len(c.events)) + for i, ev := range c.events { + ev.Time = time.Unix(int64(i), 0) + events[i] = ev + } + results := map[string]check.Result{} + for _, r := range check.Grade(ClientRules(), []check.Traffic{{Label: "connection 1", Events: events}}) { + results[r.ID] = r + } + checkVerdicts(t, results, map[string]check.Verdict{c.rule: c.want}) + }) + } +} diff --git a/internal/checks/fake_test.go b/internal/checks/fake_test.go index dbabe14..b20d454 100644 --- a/internal/checks/fake_test.go +++ b/internal/checks/fake_test.go @@ -222,6 +222,9 @@ func (s *fakeServer) handle(c net.Conn, req nrepl.Message, local map[string]bool s.eval(c, req, local) case "stdin": s.stdin(c, req, local) + case "interrupt": + // Nothing runs long enough to be interrupted. + s.send(c, req, map[string]any{"status": []any{"session-idle", "done"}}) default: switch { case q.statusString: diff --git a/internal/checks/refs.go b/internal/checks/refs.go index daf40ce..cd69c69 100644 --- a/internal/checks/refs.go +++ b/internal/checks/refs.go @@ -17,6 +17,8 @@ const ( specBase = "https://github.com/nrepl/spec.nrepl.org/blob/67796e34ac34f2f28c3af685fc3ab432fe5eb03f/spec.md" replyBase = "https://github.com/trptcolin/reply/blob/2b28587004aa3b5cd5d4548eb87f7674eb999b13/src/reply/eval_modes/nrepl.clj" rebelBase = "https://github.com/bhauman/rebel-readline/blob/d8573a61aad5cbbd83532e2050b6595cfb5b13bb/rebel-readline-nrepl/src/rebel_readline/nrepl/service/nrepl.clj" + bbNreplBase = "https://github.com/babashka/babashka.nrepl/blob/fb44874128d8cc2622f164e6a499ed4f00e5aae9/src/babashka/nrepl/" + basilispBase = "https://github.com/basilisp-lang/basilisp/blob/2f993f9e53b4195316426140384c38728304341e/src/basilisp/contrib/nrepl_server.lpy" ) func ref(name, url string) check.Ref { return check.Ref{Name: name, URL: url} } @@ -62,4 +64,18 @@ var ( specStdin = ref("spec: stdin op", specBase+"#L186-L215") ciderNeedInput = ref("CIDER need-input handling", ciderBase+"nrepl-client.el#L948-L950") nreplStdinEOF = ref("nREPL treats an empty stdin as EOF", nreplBase+"middleware/session.clj#L380-L390") + + // Server code, for the client rules. + nreplReplyID = ref("nREPL copies the id into replies only if there is one", nreplBase+"misc.clj#L74") + nreplConnLoop = ref("nREPL closes a connection it can't read a request from", nreplBase+"server.clj#L83-L90") + nreplSessions = ref("nREPL keeps sessions (and their threads) until they're closed", nreplBase+"middleware/session.clj#L20-L26") + nreplInterruptNoSes = ref("nREPL can't interrupt without a session", nreplBase+"middleware/session.clj#L271-L277") + nreplStdinSession = ref("nREPL hands stdin to the reader of the request's session", nreplBase+"middleware/session.clj#L380-L388") + nreplLineColumn = ref("nREPL casts line and column to int", nreplBase+"middleware/interruptible_eval.clj#L42-L43") + nreplEvalNs = ref("nREPL turns ns into a symbol", nreplBase+"middleware/interruptible_eval.clj#L196") + bbUnknownID = ref("babashka.nrepl replies with id \"unknown\"", bbNreplBase+"impl/utils.clj#L13") + bbSessionLoop = ref("babashka.nrepl stops reading a connection at a frame it can't handle", bbNreplBase+"impl/server.clj#L336-L345") + basilispReplyID = ref("Basilisp copies the id into replies", basilispBase+"#L51-L56") + basilispOp = ref("Basilisp turns op into a keyword", basilispBase+"#L58-L60") + basilispEvalNs = ref("Basilisp turns ns into a symbol", basilispBase+"#L132") ) diff --git a/internal/checks/wire.go b/internal/checks/wire.go index ee6cac0..e5966f0 100644 --- a/internal/checks/wire.go +++ b/internal/checks/wire.go @@ -207,7 +207,7 @@ func WireRules() []*check.Rule { func eachFrame(dir nrepl.Direction, f func(nrepl.Event, check.Reporter)) func([]nrepl.Event, check.Reporter) { return func(events []nrepl.Event, report check.Reporter) { for _, ev := range events { - if ev.Dir == dir { + if ev.Dir == dir && !ev.Closed { f(ev, report) } } @@ -282,10 +282,11 @@ type reply struct { // they got. func idKey(m nrepl.Message) (string, bool) { v, ok := m["id"] - if !ok { - return "", false - } - return fmt.Sprintf("%T %v", v, v), true + return valueKey(v), ok +} + +func valueKey(v any) string { + return fmt.Sprintf("%T %v", v, v) } // eachReply walks a connection once, annotating every received message. diff --git a/internal/proxy/proxy.go b/internal/proxy/proxy.go new file mode 100644 index 0000000..4d7adc6 --- /dev/null +++ b/internal/proxy/proxy.go @@ -0,0 +1,286 @@ +// Package proxy relays connections from nREPL clients to a server and +// records everything that passes through, so the requests of a client can +// be graded afterwards. +package proxy + +import ( + "bufio" + "errors" + "io" + "net" + "strconv" + "sync" + "time" + + "github.com/nrepl/proof/bencode" + "github.com/nrepl/proof/internal/check" + "github.com/nrepl/proof/nrepl" +) + +// Proxy accepts clients and connects each of them to the upstream server. +// The transcripts are from the client's point of view: requests are Sent +// and replies are Received. +type Proxy struct { + upstream string + ln net.Listener + // Logf, if set before Serve, is told about connections coming and + // going. + Logf func(format string, args ...any) + + mu sync.Mutex + conns []*conn + stopped bool +} + +type conn struct { + n int + client, server net.Conn + // clientDone is closed once the client's side of the connection has + // ended (or never got going). + clientDone chan struct{} + // done is closed once the connection is over and both sockets are + // closed. + done chan struct{} + + mu sync.Mutex + events []nrepl.Event +} + +// Listen starts accepting clients on addr. Call Serve to handle them. +func Listen(addr, upstream string) (*Proxy, error) { + ln, err := net.Listen("tcp", addr) + if err != nil { + return nil, err + } + return &Proxy{upstream: upstream, ln: ln}, nil +} + +// Addr is the address clients should connect to. +func (p *Proxy) Addr() string { return p.ln.Addr().String() } + +func (p *Proxy) logf(format string, args ...any) { + if p.Logf != nil { + p.Logf(format, args...) + } +} + +// Serve accepts clients until Stop is called. +func (p *Proxy) Serve() { + var delay time.Duration + for { + nc, err := p.ln.Accept() + if errors.Is(err, net.ErrClosed) { + return + } + if err != nil { + // Most likely out of file descriptors, which passes as the + // clients hang up. + delay = min(max(2*delay, 5*time.Millisecond), time.Second) + p.logf("Couldn't accept a client: %v", err) + time.Sleep(delay) + continue + } + delay = 0 + p.mu.Lock() + if p.stopped { + p.mu.Unlock() + nc.Close() + return + } + c := &conn{n: len(p.conns) + 1, client: nc, clientDone: make(chan struct{}), done: make(chan struct{})} + p.conns = append(p.conns, c) + p.mu.Unlock() + go p.handle(c) + } +} + +func (p *Proxy) handle(c *conn) { + defer close(c.done) + server, err := net.DialTimeout("tcp", p.upstream, 5*time.Second) + p.mu.Lock() + if err == nil && p.stopped { + server.Close() + err = errors.New("proof is stopping") + } + if err == nil { + c.server = server + } + p.mu.Unlock() + if err != nil { + p.logf("Connection %d: couldn't connect to %s: %v", c.n, p.upstream, err) + c.client.Close() + close(c.clientDone) + return + } + p.logf("Connection %d opened", c.n) + + go func() { + defer close(c.clientDone) + end := c.relay(c.client, c.server, nrepl.Sent) + if end == dstGone { + // The server is gone, but if the client hangs up before proof + // cuts it off, that still counts. + end = c.passOn(c.client, io.Discard, nrepl.Sent) + } + // Some servers never hang up their end, so this is when the + // connection is over as far as the client is concerned. + if end == hungUp { + p.logf("Connection %d closed", c.n) + // Let the server see the end of the requests, while any + // replies still on their way can reach the client. + closeWrite(c.server) + } + }() + switch c.relay(c.server, c.client, nrepl.Received) { + case hungUp: + p.logf("Connection %d closed by the server", c.n) + case dstGone: + // The client is gone, and its side of the relay records that. + // The server finds out the way it would without proof in between. + c.server.Close() + <-c.clientDone + } + // Without a server there's nothing more for the client to do, and + // nothing it still sends can get anywhere. (Or proof is stopping.) + c.client.Close() + c.server.Close() + <-c.clientDone +} + +// ending says how a relay ended. +type ending int + +const ( + hungUp ending = iota // src closed the connection, or reset it + dstGone // writing to dst failed + stopped // proof closed the connection +) + +// relay passes frames from src to dst exactly as they arrived, recording +// each of them (and src hanging up), and says how it ended. After a frame +// that can't be decoded the rest of the stream is passed on without being +// recorded, as there's no telling where the next frame starts. +func (c *conn) relay(src net.Conn, dst io.Writer, dir nrepl.Direction) ending { + br := bufio.NewReader(src) + dec := bencode.NewDecoder(br) + for { + v, err := dec.Decode() + ev, isFrame := nrepl.DecodeEvent(dir, v, err) + if isFrame { + c.record(ev) + if len(v.Raw) > 0 { + if _, werr := dst.Write(v.Raw); werr != nil { + return dstGone + } + } + } + switch { + case err == nil: + continue + case isFrame: + return c.passOn(br, dst, dir) + } + return c.ended(dir, err) + } +} + +// passOn copies the rest of src to dst as it is, and says how that ended. +func (c *conn) passOn(src io.Reader, dst io.Writer, dir nrepl.Direction) ending { + buf := make([]byte, 32<<10) + for { + n, err := src.Read(buf) + if n > 0 { + if _, werr := dst.Write(buf[:n]); werr != nil { + return dstGone + } + } + if err != nil { + return c.ended(dir, err) + } + } +} + +// ended records src hanging up, unless it was proof that closed it. +func (c *conn) ended(dir nrepl.Direction, err error) ending { + if errors.Is(err, net.ErrClosed) { + return stopped + } + // The end of the stream, or a reset (e.g. from a client that closed + // its socket with replies it hadn't read yet). + c.record(nrepl.Event{Dir: dir, Time: time.Now(), Closed: true}) + return hungUp +} + +func (c *conn) record(ev nrepl.Event) { + c.mu.Lock() + c.events = append(c.events, ev) + c.mu.Unlock() +} + +func closeWrite(nc net.Conn) { + if tc, ok := nc.(*net.TCPConn); ok { + tc.CloseWrite() + } +} + +// Stop stops accepting clients and returns the transcript of every +// connection in which the client sent something, in the order they were +// opened and labelled with the numbers the log uses. Clients that are +// still connected get up to grace to hang up on their own (e.g. when a +// test suite has just finished), and are then disconnected. +func (p *Proxy) Stop(grace time.Duration) []check.Traffic { + p.mu.Lock() + p.stopped = true + conns := p.conns + p.mu.Unlock() + p.ln.Close() + + deadline := time.NewTimer(grace) + defer deadline.Stop() +wait: + for _, c := range conns { + select { + case <-c.clientDone: + case <-deadline.C: + break wait + } + } + p.mu.Lock() + for _, c := range conns { + select { + case <-c.clientDone: + default: + p.logf("Connection %d was still open", c.n) + } + c.client.Close() + if c.server != nil { + c.server.Close() + } + } + p.mu.Unlock() + for _, c := range conns { + <-c.done + } + + var traffic []check.Traffic + for _, c := range conns { + c.mu.Lock() + if sentAnything(c.events) { + traffic = append(traffic, check.Traffic{Label: "connection " + strconv.Itoa(c.n), Events: c.events}) + } + c.mu.Unlock() + } + return traffic +} + +// sentAnything reports whether the client sent anything. Connections that +// only probed the port (e.g. a CI script waiting for proof to start) have +// nothing to check. +func sentAnything(events []nrepl.Event) bool { + for _, ev := range events { + if ev.Dir == nrepl.Sent && !ev.Closed { + return true + } + } + return false +} diff --git a/internal/proxy/proxy_test.go b/internal/proxy/proxy_test.go new file mode 100644 index 0000000..5741c73 --- /dev/null +++ b/internal/proxy/proxy_test.go @@ -0,0 +1,504 @@ +package proxy + +import ( + "bytes" + "errors" + "io" + "net" + "slices" + "strings" + "sync" + "testing" + "time" + + "github.com/nrepl/proof/internal/check" + "github.com/nrepl/proof/nrepl" +) + +// upstream hands every connection it accepts to serve. +func upstream(t *testing.T, serve func(net.Conn)) string { + t.Helper() + ln, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { ln.Close() }) + go func() { + for { + c, err := ln.Accept() + if err != nil { + return + } + go func() { + defer c.Close() + serve(c) + }() + } + }() + return ln.Addr().String() +} + +// sendAndHangUp sends data through p and returns whatever comes back +// before the proxy hangs up too. +func sendAndHangUp(t *testing.T, p *Proxy, data string) []byte { + t.Helper() + c, err := net.Dial("tcp", p.Addr()) + if err != nil { + t.Fatal(err) + } + defer c.Close() + c.Write([]byte(data)) + c.(*net.TCPConn).CloseWrite() + c.SetReadDeadline(time.Now().Add(2 * time.Second)) + back, _ := io.ReadAll(c) + return back +} + +// start starts a proxy to addr, and returns it along with what it logged +// so far. +func start(t *testing.T, addr string) (*Proxy, func() string) { + t.Helper() + p, err := Listen("127.0.0.1:0", addr) + if err != nil { + t.Fatal(err) + } + logged := logTo(p) + go p.Serve() + t.Cleanup(func() { p.Stop(0) }) + return p, logged +} + +// within waits for ch, and fails the test if that takes too long. +func within(t *testing.T, ch <-chan struct{}, what string) { + t.Helper() + select { + case <-ch: + case <-time.After(5 * time.Second): + t.Fatalf("timed out waiting for %s", what) + } +} + +// firstConn returns the first connection p accepted. +func firstConn(t *testing.T, p *Proxy) *conn { + t.Helper() + deadline := time.Now().Add(5 * time.Second) + for { + p.mu.Lock() + conns := p.conns + p.mu.Unlock() + if len(conns) > 0 { + return conns[0] + } + if time.Now().After(deadline) { + t.Fatal("timed out waiting for a connection") + } + time.Sleep(time.Millisecond) + } +} + +// logTo collects what p logs. +func logTo(p *Proxy) func() string { + var logged bytes.Buffer + var mu sync.Mutex + p.Logf = func(format string, args ...any) { + mu.Lock() + defer mu.Unlock() + logged.WriteString(format + "\n") + } + return func() string { + mu.Lock() + defer mu.Unlock() + return logged.String() + } +} + +func describe(events []nrepl.Event) string { + var desc []string + for _, ev := range events { + d := "->" + if ev.Dir == nrepl.Received { + d = "<-" + } + switch { + case ev.Closed: + d += " closed" + case ev.Err != nil: + d += " error " + string(ev.Raw) + default: + d += " " + ev.Msg.String() + } + if len(ev.Violations) > 0 { + d += " (not canonical)" + } + desc = append(desc, d) + } + return strings.Join(desc, "\n") +} + +// Every byte has to reach the other side as it was sent, whatever the +// proxy makes of it. +func TestRelaysEveryByteAndRecordsTheFrames(t *testing.T) { + cases := []struct { + name, requests string + want []string + }{ + { + "unsorted keys, then a frame that can't be decoded", + "d2:op8:describe2:id1:1e" + "d2:id1:22:op4:evale" + "hello", + []string{`-> {id "1", op "describe"} (not canonical)`, `-> {id "2", op "eval"}`, `-> error `, `-> closed`}, + }, + { + "a frame cut off in the middle of a string", + "d2:id1:12:op8:describee" + "d4:code10:(+ 1", + []string{`-> {id "1", op "describe"}`, `-> error d4:code10:(+ 1`, `-> closed`}, + }, + } + replies := "d2:id1:16:statusl4:doneee" + for _, c := range cases { + t.Run(c.name, func(t *testing.T) { + got := make(chan []byte, 1) + p, _ := start(t, upstream(t, func(c net.Conn) { + b, _ := io.ReadAll(c) + got <- b + c.Write([]byte(replies)) + })) + + back := sendAndHangUp(t, p, c.requests) + if b := <-got; string(b) != c.requests { + t.Errorf("server got %q, want %q", b, c.requests) + } + if string(back) != replies { + t.Errorf("client got %q, want %q", back, replies) + } + traffic := p.Stop(time.Second) + if len(traffic) != 1 || traffic[0].Label != "connection 1" { + t.Fatalf("got %v", traffic) + } + want := strings.Join(append(c.want, `<- {id "1", status ["done"]}`, `<- closed`), "\n") + if got := describe(traffic[0].Events); got != want { + t.Errorf("transcript:\n%s\nwant:\n%s", got, want) + } + }) + } +} + +// A client that closes its socket with replies it hasn't read resets the +// connection, which is still the client hanging up. +func TestResetCountsAsHangingUp(t *testing.T) { + cases := []struct { + name, requests string + want string + }{ + {"after a request", "d2:id1:12:op8:describee", `-> {id "1", op "describe"}`}, + {"after a frame that can't be decoded", "hello", `-> error `}, + } + for _, c := range cases { + t.Run(c.name, func(t *testing.T) { + received := make(chan struct{}) + p, _ := start(t, upstream(t, func(conn net.Conn) { + io.ReadFull(conn, make([]byte, len(c.requests))) + conn.Write([]byte("d2:id1:16:statusl4:doneee")) + close(received) + io.Copy(io.Discard, conn) + })) + nc, err := net.Dial("tcp", p.Addr()) + if err != nil { + t.Fatal(err) + } + nc.Write([]byte(c.requests)) + within(t, received, "the server to get the requests") + nc.(*net.TCPConn).SetLinger(0) + nc.Close() + + traffic := p.Stop(time.Second) + if len(traffic) != 1 { + t.Fatalf("got %v", traffic) + } + // The reply may or may not be recorded before the reset. + if got := describe(traffic[0].Events); !strings.HasPrefix(got, c.want+"\n") || !strings.Contains(got, "-> closed") { + t.Errorf("transcript:\n%s\nwant %s, then the hang-up", got, c.want) + } + }) + } +} + +// Once the client is gone, the server's writes fail as they would +// without proof in between, and both sockets are closed. +func TestBothSocketsAreClosedOnceTheClientIsGone(t *testing.T) { + writeFailed := make(chan struct{}) + p, _ := start(t, upstream(t, func(c net.Conn) { + io.Copy(io.Discard, c) + // Until the proxy (or the end of the test) closes the connection. + for { + if _, err := c.Write([]byte("d2:id1:16:statusl4:doneee")); err != nil { + close(writeFailed) + return + } + } + })) + nc, err := net.Dial("tcp", p.Addr()) + if err != nil { + t.Fatal(err) + } + nc.Write([]byte("d2:id1:12:op8:describee")) + nc.Close() + + c := firstConn(t, p) + // Stop would close the sockets itself, so the connection has to end + // on its own. + within(t, c.done, "the connection to end") + within(t, writeFailed, "the server's writes to fail") + for name, nc := range map[string]net.Conn{"client": c.client, "server": c.server} { + if err := nc.SetDeadline(time.Time{}); !errors.Is(err, net.ErrClosed) { + t.Errorf("the %s socket is still open", name) + } + } + if got, want := describe(c.events), "-> {id \"1\", op \"describe\"}\n-> closed"; !strings.HasPrefix(got, want) { + t.Errorf("transcript:\n%s\nwant it to start with:\n%s", got, want) + } +} + +// When the client leaves while its requests are still on their way, and +// the server finds out by writing to it, the server's connection is +// closed, as it would be without proof in between. The client's hang-up +// still makes it into the transcript. +func TestClientHangingUpWhileItsRequestsAreOnTheirWay(t *testing.T) { + p, _ := start(t, upstream(t, func(c net.Conn) { + // Replies for a client that's gone by now, while the rest of the + // request waits, so it's still on its way when the proxy finds + // the client gone. + c.Read(make([]byte, 64<<10)) + // Until the proxy (or the end of the test) closes the connection. + for { + if _, err := c.Write([]byte("d2:id1:16:statusl4:doneee")); err != nil { + return + } + } + })) + nc, err := net.Dial("tcp", p.Addr()) + if err != nil { + t.Fatal(err) + } + // More than the socket buffers on the way to the server hold. + request := bytes.Repeat([]byte("x"), len("d4:code16777216:")+16<<20+1) + copy(request, "d4:code16777216:") + request[len(request)-1] = 'e' + nc.Write(request) + nc.Close() + + c := firstConn(t, p) + within(t, c.done, "the connection to end") + if !slices.ContainsFunc(c.events, func(ev nrepl.Event) bool { return ev.Dir == nrepl.Sent && ev.Closed }) { + t.Errorf("no hang-up in the transcript:\n%s", describe(c.events[1:])) + } +} + +// A server that hangs up its end and stops reading would leave the proxy +// stuck forwarding requests to it. +func TestServerHangingUpFreesAStuckClient(t *testing.T) { + stuck, release := make(chan struct{}), make(chan struct{}) + t.Cleanup(func() { close(release) }) + p, logged := start(t, upstream(t, func(c net.Conn) { + select { + case <-stuck: + case <-release: + } + c.(*net.TCPConn).CloseWrite() + <-release + })) + nc, err := net.Dial("tcp", p.Addr()) + if err != nil { + t.Fatal(err) + } + defer nc.Close() + // Send requests until a write times out, which means the proxy is + // stuck writing to the server. + frame := []byte("d4:code1048576:" + strings.Repeat("x", 1<<20) + "e") + for { + nc.SetWriteDeadline(time.Now().Add(100 * time.Millisecond)) + if _, err := nc.Write(frame); err != nil { + break + } + } + close(stuck) + nc.SetReadDeadline(time.Now().Add(2 * time.Second)) + io.Copy(io.Discard, nc) + stopPromptly(t, p, logged) +} + +// When the server hangs up first, the client is disconnected right away, +// and that doesn't count as the client hanging up. +func TestServerHangingUpFirst(t *testing.T) { + reply := "d2:id1:16:statusl4:doneee" + p, logged := start(t, upstream(t, func(c net.Conn) { + c.Read(make([]byte, 64)) + c.Write([]byte(reply)) + })) + + nc, err := net.Dial("tcp", p.Addr()) + if err != nil { + t.Fatal(err) + } + defer nc.Close() + nc.Write([]byte("d2:id1:12:op8:describee")) + nc.SetReadDeadline(time.Now().Add(2 * time.Second)) + if back, err := io.ReadAll(nc); err != nil || string(back) != reply { + t.Fatalf("client got %q (%v), want %q and then the end", back, err, reply) + } + + traffic := stopPromptly(t, p, logged) + if len(traffic) != 1 { + t.Fatalf("got %v", traffic) + } + want := "-> {id \"1\", op \"describe\"}\n<- {id \"1\", status [\"done\"]}\n<- closed" + if got := describe(traffic[0].Events); got != want { + t.Errorf("transcript:\n%s\nwant:\n%s", got, want) + } +} + +// stopPromptly stops p, which shouldn't have to wait for connections that +// are already over. +func stopPromptly(t *testing.T, p *Proxy, logged func() string) []check.Traffic { + t.Helper() + started := time.Now() + traffic := p.Stop(5 * time.Second) + if d := time.Since(started); d > time.Second { + t.Errorf("Stop waited %s for a connection that was over", d) + } + if strings.Contains(logged(), "still open") { + t.Errorf("log:\n%s", logged()) + } + return traffic +} + +func TestStopDisconnectsClientsStillConnected(t *testing.T) { + received := make(chan struct{}) + p, logged := start(t, upstream(t, func(c net.Conn) { + c.Read(make([]byte, 64)) + close(received) + io.Copy(io.Discard, c) + })) + + c, err := net.Dial("tcp", p.Addr()) + if err != nil { + t.Fatal(err) + } + defer c.Close() + c.Write([]byte("d2:op8:describee")) + within(t, received, "the server to get the request") + + traffic := p.Stop(10 * time.Millisecond) + if len(traffic) != 1 || len(traffic[0].Events) != 1 || traffic[0].Events[0].Closed { + t.Errorf("want just the request, got %v", traffic) + } + c.SetReadDeadline(time.Now().Add(time.Second)) + if _, err := c.Read(make([]byte, 1)); err != io.EOF { + t.Errorf("client read: %v, want EOF", err) + } + if log := logged(); !strings.Contains(log, "was still open") || strings.Contains(log, "closed") { + t.Errorf("log should say the connection was still open, and only that:\n%s", log) + } +} + +// Connections that never send anything (e.g. a script checking whether the +// port is open yet) aren't clients, but they keep their number so the +// report matches the log. +func TestConnectionsThatSendNothingAreLeftOut(t *testing.T) { + p, _ := start(t, upstream(t, func(c net.Conn) { io.Copy(io.Discard, c) })) + for _, frame := range []string{"", "d2:op8:describee"} { + sendAndHangUp(t, p, frame) + } + traffic := p.Stop(time.Second) + if len(traffic) != 1 || traffic[0].Label != "connection 2" { + t.Errorf("got %v, want just connection 2", traffic) + } +} + +func TestUnreachableServer(t *testing.T) { + ln, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + addr := ln.Addr().String() + ln.Close() + p, _ := start(t, addr) + + c, err := net.Dial("tcp", p.Addr()) + if err != nil { + t.Fatal(err) + } + defer c.Close() + c.SetReadDeadline(time.Now().Add(2 * time.Second)) + if _, err := c.Read(make([]byte, 1)); err != io.EOF { + t.Errorf("client read: %v, want EOF", err) + } + if tr := p.Stop(time.Second); len(tr) != 0 { + t.Errorf("got transcripts for a connection that never reached the server: %v", tr) + } +} + +// failOnce is a listener whose first Accept fails, the way it does when +// proof runs out of file descriptors. +type failOnce struct { + net.Listener + failed bool +} + +func (l *failOnce) Accept() (net.Conn, error) { + if !l.failed { + l.failed = true + return nil, errors.New("too many open files") + } + return l.Listener.Accept() +} + +func TestKeepsAcceptingAfterAnError(t *testing.T) { + addr := upstream(t, func(c net.Conn) { + c.Read(make([]byte, 64)) + c.Write([]byte("d2:id1:16:statusl4:doneee")) + }) + ln, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + p := &Proxy{upstream: addr, ln: &failOnce{Listener: ln}} + logged := logTo(p) + go p.Serve() + t.Cleanup(func() { p.Stop(0) }) + + c, err := net.Dial("tcp", p.Addr()) + if err != nil { + t.Fatal(err) + } + defer c.Close() + c.Write([]byte("d2:id1:12:op8:describee")) + c.SetReadDeadline(time.Now().Add(2 * time.Second)) + if _, err := c.Read(make([]byte, 1)); err != nil { + t.Errorf("no reply: %v", err) + } + if !strings.Contains(logged(), "Couldn't accept a client") { + t.Errorf("the error wasn't logged:\n%s", logged()) + } +} + +type failing struct{} + +func (failing) Write(p []byte) (int, error) { return 0, errors.New("the other side is gone") } + +// A write that fails because the other side is gone isn't src hanging up, +// whether it's a frame or what comes after one that can't be decoded. +func TestFailedWritesAreNotHangUps(t *testing.T) { + for _, data := range []string{"d2:op8:describee", "hello"} { + client, proxied := net.Pipe() + go client.Write([]byte(data)) + c := &conn{} + if end := c.relay(proxied, failing{}, nrepl.Sent); end != dstGone { + t.Errorf("%q: ended with %d, want dstGone", data, end) + } + if strings.Contains(describe(c.events), "closed") { + t.Errorf("%q: transcript:\n%s", data, describe(c.events)) + } + client.Close() + proxied.Close() + } +} diff --git a/internal/report/report.go b/internal/report/report.go index fcafe7a..4aa098f 100644 --- a/internal/report/report.go +++ b/internal/report/report.go @@ -108,6 +108,8 @@ func Transcript(w io.Writer, events []nrepl.Event, indent string) { } body := "" switch { + case ev.Closed: + body = "closed the connection" case ev.Err != nil: body = fmt.Sprintf("undecodable frame (%v): %q", ev.Err, ev.Raw) case ev.Msg != nil: diff --git a/internal/report/report_test.go b/internal/report/report_test.go index c1233f0..1267ad1 100644 --- a/internal/report/report_test.go +++ b/internal/report/report_test.go @@ -9,6 +9,7 @@ import ( "time" "github.com/nrepl/proof/internal/check" + "github.com/nrepl/proof/nrepl" ) func sampleRun(server string, verdicts ...check.Verdict) Run { @@ -77,3 +78,17 @@ func TestTextMarksExpectedFailures(t *testing.T) { t.Errorf("expected failure not shown:\n%s", out) } } + +func TestTranscriptShowsWhoHungUp(t *testing.T) { + start := time.Unix(0, 0) + events := []nrepl.Event{ + {Dir: nrepl.Sent, Time: start, Msg: nrepl.Message{"id": "1", "op": "describe"}}, + {Dir: nrepl.Sent, Time: start.Add(5 * time.Millisecond), Closed: true}, + } + var buf bytes.Buffer + Transcript(&buf, events, " ") + want := " -> 0ms {id \"1\", op \"describe\"}\n -> 5ms closed the connection\n" + if buf.String() != want { + t.Errorf("got:\n%s\nwant:\n%s", buf.String(), want) + } +} diff --git a/nrepl/conn.go b/nrepl/conn.go index a72ad8d..ecf4081 100644 --- a/nrepl/conn.go +++ b/nrepl/conn.go @@ -37,6 +37,9 @@ type Event struct { // Err is set when a frame couldn't be decoded. Nothing that came after // it on the connection was decoded. Err error + // Closed means the side Dir refers to closed the connection. Nothing + // else is set. + Closed bool } // DecodeEvent records what bencode.Decoder.Decode returned: a frame, or From 5c0dca38231d3875f093fb242368c1458ee4ee72 Mon Sep 17 00:00:00 2001 From: Bozhidar Batsov Date: Wed, 7 Oct 2026 15:33:35 +0300 Subject: [PATCH 4/4] Note what clients need from the spec Request ids only have to be unique among the active requests of a connection, which is what clients actually do. The spec should also ask clients to close their sessions rather than the socket, and require an id on every request, since servers disagree on how to reply to one without it. --- doc/spec-changes.md | 27 +++++++++++++++++++++++++++ 1 file changed, 27 insertions(+) diff --git a/doc/spec-changes.md b/doc/spec-changes.md index 1cfc5d7..0cf1b1e 100644 --- a/doc/spec-changes.md +++ b/doc/spec-changes.md @@ -67,6 +67,28 @@ current session") also assumes sessions. The `stdin` and `interrupt` examples reuse the `id` of the eval request, which contradicts the spec's own rule that request IDs should be unique. +### Unique Request IDs + +The spec says that request IDs have to be unique "to the life of the +specific server process and all clients connecting to it". CIDER, neat +and mezcaml simply number the requests on each connection (so every +connection starts with `"1"`), and that works fine, as servers send the +replies to the connection the request came from. What clients really +need is to never reuse the ID of a request that's still active. The +`stdin` example above shows why. nREPL replies to the `stdin` request +with a `done`, and a client that gave it the ID of the eval ends the +eval right there. That's what proof checks for (`client.active-id`). + +### Closing the Socket Instead of the Session + +The spec says that a client may close the socket instead of sending +`close`. That doesn't go well with sessions outliving connections (see +below). nREPL and Babashka keep the sessions of a closed connection +around, and in nREPL each of them has a thread of its own. REPLy and neat +just close the socket. For now proof warns about clients that don't +close their sessions (`client.close`), and the spec should ask clients to +send `close`. + ### The Arglists in `lookup` The spec says `arglist`, but the implementations use `arglists-str` @@ -119,6 +141,11 @@ See the decisions above. - Sessions should outlive connections, and `need-input` should go to the connection that sent the eval, even when the session was created on another connection ([nrepl#183](https://github.com/nrepl/nrepl/issues/183)). +- What servers do with a request without an `id`. The spec only says + that requests "should" have one, and servers disagree on what goes in + the replies - nREPL sends them without an `id`, Babashka with + `"unknown"` and Basilisp with `""`. Either way a client can't tell them + apart, so `id` should be required. - Handling of malformed input - broken messages, top-level values that aren't dictionaries and fields of the wrong type. In [nrepl#477](https://github.com/nrepl/nrepl/issues/477) such a request