| 1 | package calls |
| 2 | |
| 3 | import ( |
| 4 | "bytes" |
| 5 | "context" |
| 6 | "encoding/base64" |
| 7 | "fmt" |
| 8 | "log/slog" |
| 9 | "net/http" |
| 10 | "net/http/httptest" |
| 11 | "net/url" |
| 12 | "path/filepath" |
| 13 | "sort" |
| 14 | "strconv" |
| 15 | "strings" |
| 16 | "sync/atomic" |
| 17 | "testing" |
| 18 | "time" |
| 19 | |
| 20 | "amadan.net/rastrillo/rastrillo/db" |
| 21 | "gorm.io/gorm" |
| 22 | ) |
| 23 | |
| 24 | // measuredKey marks the context of a request whose statements count. |
| 25 | type measuredKey struct{} |
| 26 | |
| 27 | // countingHandler counts log records, and nothing else. |
| 28 | type countingHandler struct{ n *atomic.Int64 } |
| 29 | |
| 30 | func (h countingHandler) Enabled(context.Context, slog.Level) bool { return true } |
| 31 | func (h countingHandler) Handle(context.Context, slog.Record) error { h.n.Add(1); return nil } |
| 32 | func (h countingHandler) WithAttrs([]slog.Attr) slog.Handler { return h } |
| 33 | func (h countingHandler) WithGroup(string) slog.Handler { return h } |
| 34 | |
| 35 | // TestMemberAndOutsiderDoTheSameWorkOverBudget is Astra's round-3 probe |
| 36 | // on #25 (P1). With a live invitation in the browser and the outsider |
| 37 | // budgets spent, membership used to decide what POST /signin did on the |
| 38 | // response path: a member wrote a pending row, an outsider wrote a log |
| 39 | // line and returned — 0.38–0.65 ms against 76.9–77.9 ms. Every POST now |
| 40 | // does the same synchronous work whoever it names: the same database |
| 41 | // statements, and no log line at all. The budgets still hold: the |
| 42 | // outsider is mailed nothing. |
| 43 | func TestMemberAndOutsiderDoTheSameWorkOverBudget(t *testing.T) { |
| 44 | var logs atomic.Int64 |
| 45 | logger := slog.New(countingHandler{&logs}) |
| 46 | d, err := db.Open(filepath.Join(t.TempDir(), "calls.db"), slog.New(slog.DiscardHandler)) |
| 47 | if err != nil { |
| 48 | t.Fatal(err) |
| 49 | } |
| 50 | t.Cleanup(func() { d.Close() }) |
| 51 | mail := &countingMailer{} |
| 52 | mux, a, err := buildForTest(t, d, Config{Origin: keymailOrigin, InstanceKey: "test-only-instance", |
| 53 | DEK: base64.StdEncoding.EncodeToString(bytes.Repeat([]byte{3}, 32)), AllowedAddresses: []string{plainMember}, Mailer: mail, Logger: logger}) |
| 54 | if err != nil { |
| 55 | t.Fatal(err) |
| 56 | } |
| 57 | _, tok, err := a.store.createMeeting(t.Context(), "x", nil, "person:1") |
| 58 | if err != nil { |
| 59 | t.Fatal(err) |
| 60 | } |
| 61 | join := httptest.NewRecorder() |
| 62 | mux.ServeHTTP(join, httptest.NewRequest(http.MethodGet, keymailOrigin+"/j/"+tok, nil)) |
| 63 | cookies := join.Result().Cookies() |
| 64 | if len(cookies) == 0 { |
| 65 | t.Fatal("following the invitation set no join cookie") |
| 66 | } |
| 67 | |
| 68 | var statements atomic.Int64 |
| 69 | // Only the request's own statements: the mail worker runs beside it |
| 70 | // (authorize, after the response) on a context of its own. |
| 71 | count := func(tx *gorm.DB) { |
| 72 | if tx.Statement.Context != nil && tx.Statement.Context.Value(measuredKey{}) != nil { |
| 73 | statements.Add(1) |
| 74 | } |
| 75 | } |
| 76 | cb := a.db.G.Callback() |
| 77 | for _, err := range []error{ |
| 78 | cb.Query().After("gorm:query").Register("equalwork:query", count), |
| 79 | cb.Create().After("gorm:create").Register("equalwork:create", count), |
| 80 | cb.Update().After("gorm:update").Register("equalwork:update", count), |
| 81 | cb.Delete().After("gorm:delete").Register("equalwork:delete", count), |
| 82 | cb.Raw().After("gorm:raw").Register("equalwork:raw", count), |
| 83 | cb.Row().After("gorm:row").Register("equalwork:row", count), |
| 84 | } { |
| 85 | if err != nil { |
| 86 | t.Fatal(err) |
| 87 | } |
| 88 | } |
| 89 | ip := 0 |
| 90 | post := func(form url.Values) *httptest.ResponseRecorder { |
| 91 | ip++ // a fresh client address each time, so rastrillo's per-IP budget stays out of it |
| 92 | r := httptest.NewRequest(http.MethodPost, keymailOrigin+"/signin", strings.NewReader(form.Encode())) |
| 93 | r.Header.Set("Content-Type", "application/x-www-form-urlencoded") |
| 94 | r.Header.Set("Origin", keymailOrigin) |
| 95 | r.Header.Set("Sec-Fetch-Site", "same-origin") |
| 96 | r.RemoteAddr = "198.51.100." + strconv.Itoa(ip) + ":1234" |
| 97 | r = r.WithContext(context.WithValue(r.Context(), measuredKey{}, true)) |
| 98 | for _, c := range cookies { |
| 99 | r.AddCookie(c) |
| 100 | } |
| 101 | w := httptest.NewRecorder() |
| 102 | mux.ServeHTTP(w, r) |
| 103 | return w |
| 104 | } |
| 105 | // Spend the per-link budget (five) with outsiders, each its own |
| 106 | // address so rastrillo's per-address budget stays out of it. |
| 107 | for i := 0; i < 6; i++ { |
| 108 | post(url.Values{"address": {"spender" + string(rune('a'+i)) + "@else.test"}}) |
| 109 | } |
| 110 | |
| 111 | measure := func(address string) (stmts, lines int64, took time.Duration) { |
| 112 | statements.Store(0) |
| 113 | logs.Store(0) |
| 114 | start := time.Now() |
| 115 | rec := post(url.Values{"address": {address}}) |
| 116 | took = time.Since(start) |
| 117 | if rec.Code != http.StatusSeeOther || rec.Header().Get("Location") != "/signin?sent=1" { |
| 118 | t.Fatalf("POST %s: %d %q", address, rec.Code, rec.Header().Get("Location")) |
| 119 | } |
| 120 | return statements.Load(), logs.Load(), took |
| 121 | } |
| 122 | ms, ml, _ := measure(plainMember) |
| 123 | os, ol, _ := measure("outsider@else.test") |
| 124 | if ms != os || ml != ol || ml != 0 { |
| 125 | t.Fatalf("member did %d statements and %d log lines, outsider %d and %d: want the same work and no log line on the response path", ms, ml, os, ol) |
| 126 | } |
| 127 | |
| 128 | // Astra's measurement, re-run for the record (not asserted: a |
| 129 | // stopwatch in a test is a flake, the statement count is the proof). |
| 130 | // Four more of each: rastrillo's per-address budget is five. |
| 131 | var mt, ot []time.Duration |
| 132 | for i := 0; i < 4; i++ { |
| 133 | _, _, d1 := measure(plainMember) |
| 134 | _, _, d2 := measure(fmt.Sprintf("outsider%d@else.test", i)) |
| 135 | mt, ot = append(mt, d1), append(ot, d2) |
| 136 | } |
| 137 | median := func(xs []time.Duration) time.Duration { |
| 138 | sort.Slice(xs, func(i, j int) bool { return xs[i] < xs[j] }) |
| 139 | return xs[len(xs)/2] |
| 140 | } |
| 141 | t.Logf("median POST /signin over budget: member %v, outsider %v", median(mt), median(ot)) |
| 142 | |
| 143 | a.signinMail.wait() |
| 144 | for _, to := range mail.sent() { |
| 145 | if strings.HasPrefix(to, "outsider") { |
| 146 | t.Fatalf("an over-budget outsider was mailed (%s): the budgets must still hold", to) |
| 147 | } |
| 148 | } |
| 149 | } |
| 150 | |
amadan