| 1 | package calendartest |
| 2 | |
| 3 | import ( |
| 4 | "context" |
| 5 | "fmt" |
| 6 | "io" |
| 7 | "log/slog" |
| 8 | "net/http" |
| 9 | "net/http/httptest" |
| 10 | "net/url" |
| 11 | "path/filepath" |
| 12 | "strings" |
| 13 | "sync" |
| 14 | "testing" |
| 15 | "time" |
| 16 | |
| 17 | calendar "amadan.net/oficina/calendar/internal/calendar" |
| 18 | ) |
| 19 | |
| 20 | // pickyMailer delivers everything except messages whose body contains |
| 21 | // refuse, and remembers what it actually delivered. |
| 22 | // |
| 23 | // A recorder alone cannot answer these tests: the app's own development |
| 24 | // recorder stores the body BEFORE forwarding, so it holds the last |
| 25 | // message ATTEMPTED rather than the last one delivered — which is |
| 26 | // exactly the distinction a test about failed sends has to make. |
| 27 | type pickyMailer struct { |
| 28 | refuse string |
| 29 | |
| 30 | mu sync.Mutex |
| 31 | delivered []string |
| 32 | recipients []string |
| 33 | attempts int |
| 34 | } |
| 35 | |
| 36 | func (m *pickyMailer) Send(_ context.Context, to, subject, body string) error { |
| 37 | m.mu.Lock() |
| 38 | defer m.mu.Unlock() |
| 39 | m.attempts++ |
| 40 | if m.refuse != "" && strings.Contains(to+subject+body, m.refuse) { |
| 41 | // Shaped like the real thing: rastrillo's mailer formats the |
| 42 | // recipient into its error, which is what scrub exists for. |
| 43 | return fmt.Errorf("send to nobody@example.com: connection refused") |
| 44 | } |
| 45 | m.delivered = append(m.delivered, subject+"\n"+body) |
| 46 | m.recipients = append(m.recipients, to) |
| 47 | return nil |
| 48 | } |
| 49 | |
| 50 | func (m *pickyMailer) count() int { |
| 51 | m.mu.Lock() |
| 52 | defer m.mu.Unlock() |
| 53 | return len(m.delivered) |
| 54 | } |
| 55 | |
| 56 | func (m *pickyMailer) to(i int) string { |
| 57 | m.mu.Lock() |
| 58 | defer m.mu.Unlock() |
| 59 | if i < 0 || i >= len(m.recipients) { |
| 60 | return "" |
| 61 | } |
| 62 | return m.recipients[i] |
| 63 | } |
| 64 | |
| 65 | func (m *pickyMailer) body(i int) string { |
| 66 | m.mu.Lock() |
| 67 | defer m.mu.Unlock() |
| 68 | if i < 0 || i >= len(m.delivered) { |
| 69 | return "" |
| 70 | } |
| 71 | return m.delivered[i] |
| 72 | } |
| 73 | |
| 74 | func (m *pickyMailer) reset() { |
| 75 | m.mu.Lock() |
| 76 | defer m.mu.Unlock() |
| 77 | m.delivered, m.recipients = nil, nil |
| 78 | } |
| 79 | |
| 80 | func (m *pickyMailer) deliveredContaining(needle string) bool { |
| 81 | m.mu.Lock() |
| 82 | defer m.mu.Unlock() |
| 83 | for _, d := range m.delivered { |
| 84 | if strings.Contains(d, needle) { |
| 85 | return true |
| 86 | } |
| 87 | } |
| 88 | return false |
| 89 | } |
| 90 | |
| 91 | // newAppWithMailer builds an app whose outgoing mail goes through |
| 92 | // mailer. Env stays "development", so the sign-in recorder still works |
| 93 | // and SignInForTest can drive a real sign-in. |
| 94 | func newAppWithMailer(t *testing.T, mailer *pickyMailer) *calendar.App { |
| 95 | t.Helper() |
| 96 | app, err := calendar.New(calendar.Config{ |
| 97 | DBPath: filepath.Join(t.TempDir(), "calendar.db"), |
| 98 | Env: "development", |
| 99 | Origin: testOrigin, |
| 100 | Mailer: mailer, |
| 101 | Logger: slog.New(slog.NewTextHandler(io.Discard, nil)), |
| 102 | }) |
| 103 | if err != nil { |
| 104 | t.Fatalf("calendar.New: %v", err) |
| 105 | } |
| 106 | t.Cleanup(func() { app.Close() }) |
| 107 | return app |
| 108 | } |
| 109 | |
| 110 | func tick(t *testing.T, h http.Handler) *httptest.ResponseRecorder { |
| 111 | t.Helper() |
| 112 | req := httptest.NewRequest(http.MethodPost, "/jobs/reminders", nil) |
| 113 | req.Header.Set("Authorization", "Bearer test-token") |
| 114 | rec := httptest.NewRecorder() |
| 115 | h.ServeHTTP(rec, req) |
| 116 | return rec |
| 117 | } |
| 118 | |
| 119 | // ONE undeliverable address must not hold up everybody else's |
| 120 | // reminders. |
| 121 | // |
| 122 | // The bug this pins: FailReminder used to CLEAR claimed_at, which put |
| 123 | // the failing row straight back at the head of ClaimDueReminder's |
| 124 | // "ORDER BY due_at ASC". The next claim in the same pass returned the |
| 125 | // same row, the drain's seen-guard tripped, and the pass returned with |
| 126 | // every reminder behind it unsent — so one bounced mailbox silently |
| 127 | // delayed the whole team's reminders until the next tick, and the log |
| 128 | // blamed a double claim rather than the address. |
| 129 | func TestOneUndeliverableReminderDoesNotBlockTheRest(t *testing.T) { |
| 130 | t.Setenv("CARLOS_ADMIN_TOKEN", "test-token") |
| 131 | |
| 132 | mailer := &pickyMailer{refuse: "Wedged"} |
| 133 | app := newAppWithMailer(t, mailer) |
| 134 | session := app.SignInForTest(t, "someone@example.com") |
| 135 | h := app.Handler() |
| 136 | |
| 137 | // Both already inside their ten-minute default warning, and the |
| 138 | // wedged one is due FIRST so it is claimed first. UTC because that |
| 139 | // is the test person's zone. |
| 140 | now := time.Now().UTC() |
| 141 | for _, e := range []struct { |
| 142 | title string |
| 143 | at time.Time |
| 144 | }{ |
| 145 | {"Wedged meeting", now.Add(1 * time.Minute)}, |
| 146 | {"Meeting behind it", now.Add(3 * time.Minute)}, |
| 147 | } { |
| 148 | createEvent(t, h, session, url.Values{ |
| 149 | "title": {e.title}, |
| 150 | "start": {e.at.Format("2006-01-02T15:04")}, |
| 151 | "end": {e.at.Add(15 * time.Minute).Format("2006-01-02T15:04")}, |
| 152 | "kind": {"meeting"}, |
| 153 | "status": {"confirmed"}, |
| 154 | "repeat": {"none"}, |
| 155 | }) |
| 156 | } |
| 157 | |
| 158 | if rec := tick(t, h); rec.Code != http.StatusNoContent { |
| 159 | t.Fatalf("drain: status %d, want 204\n%s", rec.Code, rec.Body.String()) |
| 160 | } |
| 161 | |
| 162 | if !mailer.deliveredContaining("Meeting behind it") { |
| 163 | t.Error("the reminder behind an undeliverable one was never sent — " + |
| 164 | "one bad address is blocking the queue") |
| 165 | } |
| 166 | if mailer.deliveredContaining("Wedged meeting") { |
| 167 | t.Error("the mailer reported refusing this message but it was recorded as delivered") |
| 168 | } |
| 169 | } |
| 170 | |
| 171 | // Giving up on a recurring reminder must not kill the series. |
| 172 | // |
| 173 | // The bug this pins: on the final attempt FailReminder marked the queue |
| 174 | // row fired and stopped. Nothing queued the next occurrence, NextDueAt |
| 175 | // ignored a fired row, and a daily standup that hit a relay outage lost |
| 176 | // its reminders permanently and silently. The undeliverable fact now |
| 177 | // lives on the RULE (Reminder.UndeliverableAt) so the queue row is free |
| 178 | // to move on. |
| 179 | func TestGivingUpOnARecurringReminderKeepsTheSeriesAlive(t *testing.T) { |
| 180 | t.Setenv("CARLOS_ADMIN_TOKEN", "test-token") |
| 181 | |
| 182 | mailer := &pickyMailer{refuse: "Doomed"} |
| 183 | app := newAppWithMailer(t, mailer) |
| 184 | session := app.SignInForTest(t, "someone@example.com") |
| 185 | h := app.Handler() |
| 186 | |
| 187 | start := time.Now().UTC().Add(1 * time.Minute) |
| 188 | createEvent(t, h, session, url.Values{ |
| 189 | "title": {"Doomed standup"}, |
| 190 | "start": {start.Format("2006-01-02T15:04")}, |
| 191 | "end": {start.Add(15 * time.Minute).Format("2006-01-02T15:04")}, |
| 192 | "kind": {"meeting"}, |
| 193 | "status": {"confirmed"}, |
| 194 | "repeat": {"daily"}, |
| 195 | }) |
| 196 | |
| 197 | // Stand the row up on its LAST attempt rather than waiting out five |
| 198 | // five-minute claim leases. The lease is the backoff the fix above |
| 199 | // introduced, so burning the attempts honestly would take ~25 |
| 200 | // minutes of wall clock. |
| 201 | db := app.DBForTest() |
| 202 | if _, err := db.Exec( |
| 203 | `UPDATE reminder_queues SET attempts = ?, claimed_at = NULL`, |
| 204 | calendar.MaxReminderAttempts-1); err != nil { |
| 205 | t.Fatalf("priming the queue row: %v", err) |
| 206 | } |
| 207 | |
| 208 | if rec := tick(t, h); rec.Code != http.StatusNoContent { |
| 209 | t.Fatalf("drain: status %d, want 204", rec.Code) |
| 210 | } |
| 211 | |
| 212 | // The series is still scheduled: the next occurrence is queued, |
| 213 | // roughly a day out. |
| 214 | due := app.NextDue() |
| 215 | if due.IsZero() { |
| 216 | t.Fatal("giving up on one occurrence unqueued the whole series — " + |
| 217 | "this rule will never remind anybody again") |
| 218 | } |
| 219 | if until := time.Until(due); until < 20*time.Hour || until > 26*time.Hour { |
| 220 | t.Errorf("the requeued reminder is %v away, want about a day", until) |
| 221 | } |
| 222 | |
| 223 | // And the failure is still visible rather than erased by the |
| 224 | // reschedule. |
| 225 | var n int |
| 226 | if err := db.QueryRow( |
| 227 | `SELECT COUNT(*) FROM reminders WHERE undeliverable_at IS NOT NULL`).Scan(&n); err != nil { |
| 228 | t.Fatalf("counting undeliverable rules: %v", err) |
| 229 | } |
| 230 | if n != 1 { |
| 231 | t.Errorf("%d rules marked undeliverable, want 1 — "+ |
| 232 | "rescheduling erased the record of the failure", n) |
| 233 | } |
| 234 | } |
| 235 | |
| 236 | // An address that is not on the allowlist must leave a trace in the |
| 237 | // LOG, even though it deliberately leaves none in the response. |
| 238 | // |
| 239 | // The two rules that meet here were pulling the same way by accident: |
| 240 | // the response must be byte-identical to a real send (anti-enumeration) |
| 241 | // and no address may be written to a log line (AGENTS.md §Logs). Obeying |
| 242 | // both by staying completely silent made a misconfigured allowlist |
| 243 | // undiagnosable from outside AND from `carlos logs` — which is how a |
| 244 | // real person came to sit waiting for a link that was never sent. |
| 245 | func TestARefusedSignInIsCountedInTheLog(t *testing.T) { |
| 246 | var log strings.Builder |
| 247 | app, err := calendar.New(calendar.Config{ |
| 248 | DBPath: filepath.Join(t.TempDir(), "calendar.db"), |
| 249 | Env: "development", |
| 250 | Origin: testOrigin, |
| 251 | AllowedAddresses: "allowed@example.com", |
| 252 | Logger: slog.New(slog.NewTextHandler(&log, nil)), |
| 253 | }) |
| 254 | if err != nil { |
| 255 | t.Fatalf("calendar.New: %v", err) |
| 256 | } |
| 257 | t.Cleanup(func() { app.Close() }) |
| 258 | |
| 259 | post(t, app.Handler(), "/signin", url.Values{"address": {"stranger@example.com"}}) |
| 260 | app.FlushSigninMailForTest() // refusals are logged after the response |
| 261 | |
| 262 | out := log.String() |
| 263 | if !strings.Contains(out, "signin refused by allowlist") { |
| 264 | t.Errorf("a refused sign-in left no trace in the log:\n%s", out) |
| 265 | } |
| 266 | // The trace must not be the thing the logs rule forbids. |
| 267 | if strings.Contains(out, "stranger@example.com") { |
| 268 | t.Errorf("the refusal log names the address, which AGENTS.md forbids:\n%s", out) |
| 269 | } |
| 270 | } |
| 271 | |
| 272 | // A list written with the wrong separator must refuse to boot rather |
| 273 | // than admit nobody. |
| 274 | // |
| 275 | // Splitting on "," alone turns "a@x.com;b@y.com" into ONE entry that is |
| 276 | // nobody's address, which is a non-empty allowlist and therefore a |
| 277 | // successful boot — the exact "quietly admits nobody" state the empty |
| 278 | // check was written to prevent, reached by a different route. |
| 279 | func TestAnAllowlistWithTheWrongSeparatorRefusesToStart(t *testing.T) { |
| 280 | for _, list := range []string{ |
| 281 | "a@example.com;b@example.com", |
| 282 | "a@example.com b@example.com", |
| 283 | "nonsense", |
| 284 | } { |
| 285 | _, err := calendar.New(calendar.Config{ |
| 286 | DBPath: filepath.Join(t.TempDir(), "calendar.db"), |
| 287 | Env: "production", |
| 288 | Origin: testOrigin, |
| 289 | InstanceKey: "test-instance-key", |
| 290 | Mailer: &pickyMailer{}, |
| 291 | AllowedAddresses: list, |
| 292 | Logger: slog.New(slog.NewTextHandler(io.Discard, nil)), |
| 293 | }) |
| 294 | if err == nil { |
| 295 | t.Errorf("$CALENDAR_ALLOWED_ADDRESSES = %q booted successfully; "+ |
| 296 | "it admits nobody and looks perfectly healthy", list) |
| 297 | } |
| 298 | } |
| 299 | } |
| 300 | |
amadan