| 1 | //go:build browser |
| 2 | |
| 3 | // The browser gate: a real call, in real Chromium, between two real |
| 4 | // browser contexts with fake cameras. |
| 5 | // |
| 6 | // make browser |
| 7 | // |
| 8 | // Not part of the plain suite and not part of `make ci`: it needs node |
| 9 | // and an npm install, and the gate the team runs on every push must not |
| 10 | // depend on a toolchain the app itself does not use. |
| 11 | // |
| 12 | // Every other test in this repo lives inside one layer. The Go suite |
| 13 | // asks Go what Go produced; room.js was landed with nothing but |
| 14 | // `node --check` behind it. Everything in the media half — |
| 15 | // getUserMedia, the offer/answer exchange, trickle ICE, a decoded frame, |
| 16 | // the resume ladder, the takeover refusal — first runs here. |
| 17 | // |
| 18 | // Go owns the half a browser cannot reach: it starts the app on a real |
| 19 | // port (the origin is load-bearing — csrf.Protect measures against it), |
| 20 | // signs the two members in through the actual magic-link flow so it can |
| 21 | // read the mailer, creates the meeting, and restarts the process on the |
| 22 | // same port when the restart scenario asks for it. node owns the |
| 23 | // browser. They talk over the node process's own stdin and stdout: node |
| 24 | // writes a line beginning "CONTROL ", Go answers with one line. |
| 25 | package callstest |
| 26 | |
| 27 | import ( |
| 28 | "bufio" |
| 29 | "bytes" |
| 30 | "context" |
| 31 | "encoding/base64" |
| 32 | "encoding/json" |
| 33 | "fmt" |
| 34 | "html" |
| 35 | "io" |
| 36 | "log/slog" |
| 37 | "net" |
| 38 | "net/http" |
| 39 | "net/http/cookiejar" |
| 40 | "net/url" |
| 41 | "os" |
| 42 | "os/exec" |
| 43 | "path/filepath" |
| 44 | "regexp" |
| 45 | "runtime" |
| 46 | "strings" |
| 47 | "sync" |
| 48 | "testing" |
| 49 | "time" |
| 50 | |
| 51 | "amadan.net/rastrillo/rastrillo" |
| 52 | "amadan.net/rastrillo/rastrillo/db" |
| 53 | |
| 54 | "amadan.net/oficina/calls/internal/calls" |
| 55 | ) |
| 56 | |
| 57 | // scenarioTimeout is per scenario, not for the run: a call that has not |
| 58 | // connected in three minutes is not slow, it is broken. |
| 59 | const scenarioTimeout = 3 * time.Minute |
| 60 | |
| 61 | // memberA and memberB are the two AllowedAddresses this gate signs in. |
| 62 | // A guest signs itself in from the browser, through the emailed link, |
| 63 | // with an address that is deliberately not on the list. |
| 64 | // |
| 65 | // The two local parts differ, and that is load-bearing rather than |
| 66 | // cosmetic: a display name is the address up to the "@", so the rest of |
| 67 | // this package's `paul@example.com`/`paul@rslw.com` pair would give both |
| 68 | // contexts here the name "paul". Every assertion about whose name is on |
| 69 | // an arriving chat line, or in "<name>’s screen", would then hold just |
| 70 | // as well with the wrong name on it. |
| 71 | const ( |
| 72 | memberA = "paul@example.com" |
| 73 | memberB = "bea@rslw.com" |
| 74 | ) |
| 75 | |
| 76 | // scenarios are the passes, in the order they run. Each gets its own |
| 77 | // node process and its own freshly restarted app, so a participation one |
| 78 | // scenario left behind cannot 409 the next one's fresh stream. |
| 79 | // |
| 80 | // All of them pass. A scenario that starts failing on the client rather |
| 81 | // than on the gate keeps its place here and its assertions as written, |
| 82 | // and is skipped from inside its own subtest with t.Skip carrying the |
| 83 | // exact failure — never deleted, and never quietly loosened. |
| 84 | var scenarios = []string{ |
| 85 | "guestdirect", |
| 86 | "layout", |
| 87 | "glyphs", |
| 88 | "stage", |
| 89 | "window", |
| 90 | "title", |
| 91 | "chrome", |
| 92 | "devices", |
| 93 | "audiotest", |
| 94 | "call", |
| 95 | "mute", |
| 96 | "meters", |
| 97 | "spacemute", |
| 98 | "switching", |
| 99 | "share", |
| 100 | "mutualshare", |
| 101 | "laterolls", |
| 102 | "renewal", |
| 103 | "ice", |
| 104 | "icerenewal", |
| 105 | "icefail", |
| 106 | "icestuck", |
| 107 | "guest", |
| 108 | "speaker", |
| 109 | "chat", |
| 110 | "removed", |
| 111 | "allowlist", |
| 112 | "departure", |
| 113 | "staletarget", |
| 114 | "probehang", |
| 115 | "replay", |
| 116 | "gap", |
| 117 | "resetretry", |
| 118 | "senddeadline", |
| 119 | "sendhang", |
| 120 | "rosterpair", |
| 121 | "restart", |
| 122 | "takeover", |
| 123 | "crosssite", |
| 124 | "stall", |
| 125 | "signedout", |
| 126 | "nowebrtc", |
| 127 | "playfallback", |
| 128 | "autoplay", |
| 129 | "connecting", |
| 130 | "quality", |
| 131 | "scriptless", |
| 132 | } |
| 133 | |
| 134 | // skipped are the scenarios whose assertions are right and whose client |
| 135 | // is not. Each keeps its place in `scenarios` above and every assertion |
| 136 | // as written; what is recorded here is the exact failure the gate |
| 137 | // printed and the round that owns the fix. Delete an entry to put a |
| 138 | // scenario back in the gate — that, and nothing else, is what "fixed" |
| 139 | // means. |
| 140 | // |
| 141 | // FIXED in Task 4's fix round 2 — see task-4-report.md. The account |
| 142 | // below is left as written because it is what the fix was made against, |
| 143 | // and because the last paragraph of it is still true of `accept`. |
| 144 | // |
| 145 | // All three ICE scenarios shared one defect, and it was not in them: |
| 146 | // |
| 147 | // room.js applyRoster captures the roster, awaits the /ice fetch |
| 148 | // (§5.2's ordering), and then reconciles the roster it captured |
| 149 | // BEFORE the await. A `peer` event that arrives during the fetch — |
| 150 | // ten milliseconds after the roster, in the run below — builds a |
| 151 | // connection that the stale roster does not name, so reconcile |
| 152 | // closes it with forget=true. That drops seqOut and lastIn for that |
| 153 | // peer (closePC's own comment: the counters are kept only on a |
| 154 | // rebuild). The connection is built again by the next message, its |
| 155 | // outbound numbering restarts at 1, and the other browser — whose |
| 156 | // lastIn for this peer is still 3 — drops the answer as already |
| 157 | // seen. It stays at have-local-offer with nothing to retry, and the |
| 158 | // call never connects. |
| 159 | // |
| 160 | // Watched directly: with /ice held 1200 ms by the gate's own route, one |
| 161 | // browser logged `setConfiguration ok, restartIce ok, close ok` and then |
| 162 | // a fresh connection, posting `answer seq=1` where the peer had already |
| 163 | // recorded seq=3 from it. It is a race, not a certainty: the same |
| 164 | // scenarios pass when the fetch beats the `peer` event, which is most of |
| 165 | // the time on a loopback and none of the time on a busy machine — two |
| 166 | // consecutive full `make browser` runs each lost one or two of the three |
| 167 | // to it. Nothing about it is specific to the relay; a relay only makes |
| 168 | // /ice slow enough to notice. |
| 169 | // |
| 170 | // The stale roster is what opens the hole, but the thing that kills the |
| 171 | // call is one line older than this slice: `accept` tests the replay |
| 172 | // guard BEFORE the generation, so the first message of a renumbered |
| 173 | // connection — seq 1, where lastIn already says 3 — is discarded as a |
| 174 | // replay whatever generation it carries. `staletarget` failed with the |
| 175 | // identical signature (stable/connecting against have-local-offer, |
| 176 | // frames {}, rosters 10) in a run of this same gate with no relay |
| 177 | // configured anywhere, which is the flake Task 4's fix round recorded as |
| 178 | // "watch" and could not explain. Same defect, different door. |
| 179 | // |
| 180 | // The fix is Task 4's own suggestion, from its report's last concern: |
| 181 | // reconcile the roster this browser holds when the await returns, or |
| 182 | // build connections at once and adopt the servers when the list lands — |
| 183 | // and, under it, an `accept` that lets a new generation past the cursor |
| 184 | // it is renumbering. |
| 185 | // Empty, and the account above is kept because it is the clearest one |
| 186 | // this branch has of a defect that cost two slices a flake each. Task |
| 187 | // 4's fix round 2 closed three doors onto it, not the two the account |
| 188 | // above describes: applyRoster reconciles the roster held when the |
| 189 | // fetch returns; a close from reconcile no longer forgets §4.6's |
| 190 | // counters for a peer the hub may still name; and — the one that was |
| 191 | // actually killing these scenarios — a roster cannot close a connection |
| 192 | // built after the hub sent it. That third one is missing from the |
| 193 | // account because the account is missing the fact under it: the hub |
| 194 | // does not re-send a roster when someone joins, it sends `peer` to the |
| 195 | // people already there, so for the commonest case there is no newer |
| 196 | // roster for the first door to prefer. The three ICE scenarios and |
| 197 | // staletarget have run in the gate ever since. |
| 198 | var skipped = map[string]string{ |
| 199 | // FIXED in Task 4's fix round 2 — see task-4-report.md. mutualshare |
| 200 | // has run in the gate ever since, and the account below is left as |
| 201 | // written because it is what the fix was made against. What it could |
| 202 | // not know is where the damage came from: not the m-line matching it |
| 203 | // suspected, but the rollback itself. Chromium rebuilds every send |
| 204 | // stream on a connection when it rolls back an offer that added an |
| 205 | // m-line, and the camera's comes back having encoded nothing. The |
| 206 | // fix is that the side which would roll back gives way before it |
| 207 | // offers, so nothing collides — see POLITE_YIELD in room.js. |
| 208 | // |
| 209 | // Task 4 fix round 2 owns this. The scenario keeps its place above |
| 210 | // and every assertion as written; what follows is exactly what the |
| 211 | // gate printed, and the evidence under it. |
| 212 | // |
| 213 | // mutualshare drives §5.4 the one way `share` cannot: both peers |
| 214 | // click Share screen together, three rounds of stop-and-share, and |
| 215 | // then one stops while the other carries on. Every screen assertion |
| 216 | // passes in every round — announced, captioned with the right name, |
| 217 | // decoding real frames, negotiation settling and staying settled, |
| 218 | // displaySurface saying both are really capturing a display. What |
| 219 | // fails is the camera, from the first mutual share onwards: |
| 220 | // |
| 221 | // FAIL round 2: member A is still receiving the other's camera (5 -> 5) |
| 222 | // FAIL round 2: member B is still receiving the other's camera (6 -> 6) |
| 223 | // FAIL round 3: member A is still receiving the other's camera (5 -> 5) |
| 224 | // FAIL round 3: member B is still receiving the other's camera (6 -> 6) |
| 225 | // FAIL member B still has the camera through the one-sided stop (6 -> 6) |
| 226 | // |
| 227 | // Round 1 passes only because 5 > 3: the count moves twice and then |
| 228 | // stops for the remaining seventy seconds, while the two screens go |
| 229 | // on to six hundred frames each on the same connections. |
| 230 | // |
| 231 | // It is not the tile, the counter or the encoder. Per-connection |
| 232 | // getStats, from the run that produced the lines above: |
| 233 | // |
| 234 | // A (has stopped sharing; audio mid 0, camera mid 1, B's screen mid 6): |
| 235 | // transceivers ["0 sendrecv/sendrecv:audio", "1 sendrecv/sendrecv:video", "6 recvonly/recvonly:video"] |
| 236 | // inbound [{ssrc 2155371570, framesReceived 513, framesDecoded 512, framesDropped 0, pliCount 0, freezeCount 0, muted false} |
| 237 | // {ssrc 572440383, framesReceived 513, framesDecoded 513, framesDropped 1, pliCount 1, freezeCount 0, muted true}] |
| 238 | // outbound [{ssrc 991534554, framesSent 0, framesEncoded 0, active true, limited "none"}] |
| 239 | // |
| 240 | // B (still sharing; audio 0, camera 1, its own screen 6, A's screen 7): |
| 241 | // transceivers ["0 sendrecv/sendrecv:audio", "1 sendrecv/sendrecv:video", "6 sendonly/sendonly:video", "7 recvonly/recvonly:video"] |
| 242 | // inbound [{ssrc 4101167316, framesReceived 508, framesDecoded 507, framesDropped 0, pliCount 0, freezeCount 0, muted false} |
| 243 | // {ssrc 991534554, framesReceived 6, framesDecoded 6, framesDropped 0, pliCount 1, freezeCount 0, muted true}] |
| 244 | // outbound [{ssrc 2155371570, framesSent 508, framesEncoded 508, active true, limited "none"} |
| 245 | // {ssrc 572440383, framesSent 1146, framesEncoded 1146, active true, limited "none"}] |
| 246 | // |
| 247 | // Two facts, and they are the whole diagnosis. A's only outbound |
| 248 | // video stream has sent zero frames and encoded zero frames, with |
| 249 | // active true and a quality limitation of "none" — so this is not a |
| 250 | // starved encoder in a headless browser, it is a stream that never |
| 251 | // started. A's camera track is live and its m-line is mid 1 at |
| 252 | // sendrecv/sendrecv throughout, which means the SSRC on that m-line |
| 253 | // was replaced by a renegotiation and the new one never encoded. |
| 254 | // And in the other direction B's camera is sending healthily (1146 |
| 255 | // frames) and arriving at A (513 received) on a receiver whose track |
| 256 | // reports muted true, so none of it reaches the tile. |
| 257 | // |
| 258 | // Both are outcomes of the simultaneous renegotiation: two peers |
| 259 | // adding a share transceiver to one connection in the same moment, |
| 260 | // one of them rolling its own offer back. Neither is visible when |
| 261 | // only one side shares, which is why `share` passes. |
| 262 | // |
| 263 | // The fix belongs in room.js and nowhere in this gate. Delete this |
| 264 | // entry to put the scenario back — that, and nothing else, is what |
| 265 | // "fixed" means. |
| 266 | } |
| 267 | |
| 268 | func TestCallInARealBrowser(t *testing.T) { |
| 269 | rig := newBrowserRig(t) |
| 270 | sqid, token := rig.createMeeting(t) |
| 271 | rig.sqid, rig.token = sqid, token |
| 272 | |
| 273 | for _, name := range scenarios { |
| 274 | t.Run(name, func(t *testing.T) { |
| 275 | if why, ok := skipped[name]; ok { |
| 276 | t.Skip(why) |
| 277 | } |
| 278 | // The relay contract is a per-scenario setting, applied by |
| 279 | // the restart below and by every restart the scenario asks |
| 280 | // for afterwards: the room page carries `data-relay` from |
| 281 | // the app that rendered it, so it has to be in place before |
| 282 | // the browser opens anything, and a scenario that is not |
| 283 | // about the relay must still see §5.5's floor. |
| 284 | rig.wantRelay(strings.HasPrefix(name, "ice")) |
| 285 | |
| 286 | // A fresh hub per scenario. The session cookies and the |
| 287 | // meeting live in the database and survive; the hub's |
| 288 | // participations do not, which is exactly what is wanted — |
| 289 | // a tab that did not manage to send `leave` would otherwise |
| 290 | // hold this session's one peer slot into the next scenario. |
| 291 | rig.restart(t) |
| 292 | rig.reportsFrom = rig.reports.size() |
| 293 | rig.run(t, name, sqid, token) |
| 294 | }) |
| 295 | } |
| 296 | } |
| 297 | |
| 298 | // browserRig is the app under a real listener, plus the two signed-in |
| 299 | // members' cookies and the mail recorder a guest's own sign-in needs. |
| 300 | type browserRig struct { |
| 301 | dbPath string |
| 302 | d *db.DB |
| 303 | mail *recordingMailer |
| 304 | |
| 305 | addr string |
| 306 | origin string |
| 307 | |
| 308 | mu sync.Mutex |
| 309 | ln net.Listener |
| 310 | srv *http.Server |
| 311 | ctl *calls.TestHandle |
| 312 | relay bool |
| 313 | |
| 314 | cookieName string |
| 315 | cookieA string |
| 316 | cookieB string |
| 317 | |
| 318 | // reports is every quality and problem report line the app has |
| 319 | // written (spec §15.26), as the deployed app writes them: JSON. |
| 320 | reports reportLog |
| 321 | |
| 322 | // The meeting and its link, which a report log must never contain. |
| 323 | sqid string |
| 324 | token string |
| 325 | // reportsFrom is where the current scenario's report lines start: |
| 326 | // the log is the rig's, and every scenario before this one wrote to |
| 327 | // it too. |
| 328 | reportsFrom int |
| 329 | } |
| 330 | |
| 331 | // reportLog is a goroutine-safe sink for the app's report logger. |
| 332 | type reportLog struct { |
| 333 | mu sync.Mutex |
| 334 | buf bytes.Buffer |
| 335 | } |
| 336 | |
| 337 | func (l *reportLog) Write(p []byte) (int, error) { |
| 338 | l.mu.Lock() |
| 339 | defer l.mu.Unlock() |
| 340 | return l.buf.Write(p) |
| 341 | } |
| 342 | |
| 343 | // raw is everything written so far. |
| 344 | func (l *reportLog) raw() string { |
| 345 | l.mu.Lock() |
| 346 | defer l.mu.Unlock() |
| 347 | return l.buf.String() |
| 348 | } |
| 349 | |
| 350 | // size is how much has been written, for linesFrom. |
| 351 | func (l *reportLog) size() int { |
| 352 | l.mu.Lock() |
| 353 | defer l.mu.Unlock() |
| 354 | return l.buf.Len() |
| 355 | } |
| 356 | |
| 357 | // lines are the report lines with msg, decoded. |
| 358 | func (l *reportLog) lines(msg string) []map[string]any { |
| 359 | return l.linesFrom(0, msg) |
| 360 | } |
| 361 | |
| 362 | // linesFrom are the report lines with msg written at or after offset. |
| 363 | func (l *reportLog) linesFrom(offset int, msg string) []map[string]any { |
| 364 | raw := l.raw() |
| 365 | if offset > len(raw) { |
| 366 | offset = len(raw) |
| 367 | } |
| 368 | var out []map[string]any |
| 369 | for _, line := range strings.Split(raw[offset:], "\n") { |
| 370 | var m map[string]any |
| 371 | if json.Unmarshal([]byte(line), &m) == nil && m["msg"] == msg { |
| 372 | out = append(out, m) |
| 373 | } |
| 374 | } |
| 375 | return out |
| 376 | } |
| 377 | |
| 378 | func newBrowserRig(t *testing.T) *browserRig { |
| 379 | t.Helper() |
| 380 | |
| 381 | // The listener first: the origin is the CSRF yardstick and the base |
| 382 | // of every emailed link, so the app cannot be built until the kernel |
| 383 | // has named the port. |
| 384 | ln, err := net.Listen("tcp", "127.0.0.1:0") |
| 385 | if err != nil { |
| 386 | t.Fatalf("listen: %v", err) |
| 387 | } |
| 388 | rig := &browserRig{ |
| 389 | dbPath: filepath.Join(t.TempDir(), "calls.db"), |
| 390 | mail: &recordingMailer{}, |
| 391 | addr: ln.Addr().String(), |
| 392 | } |
| 393 | rig.origin = "http://" + rig.addr |
| 394 | |
| 395 | logger := slog.New(slog.NewTextHandler(io.Discard, nil)) |
| 396 | d, err := db.Open(rig.dbPath, logger) |
| 397 | if err != nil { |
| 398 | t.Fatalf("db.Open: %v", err) |
| 399 | } |
| 400 | t.Cleanup(func() { d.Close() }) |
| 401 | rig.d = d |
| 402 | |
| 403 | rig.serve(t, ln) |
| 404 | t.Cleanup(func() { rig.stop() }) |
| 405 | |
| 406 | rig.cookieName, rig.cookieA = rig.signIn(t, memberA) |
| 407 | _, rig.cookieB = rig.signIn(t, memberB) |
| 408 | return rig |
| 409 | } |
| 410 | |
| 411 | // serve builds a fresh app over the same database and puts it behind ln. |
| 412 | func (rig *browserRig) serve(t *testing.T, ln net.Listener) { |
| 413 | t.Helper() |
| 414 | mux, ctl, err := calls.NewForTest(rig.d, calls.Config{ |
| 415 | Env: calls.EnvDevelopment, |
| 416 | Origin: rig.origin, |
| 417 | AllowedAddresses: []string{memberA, memberB}, |
| 418 | Mailer: rig.mail, |
| 419 | Logger: slog.New(slog.NewTextHandler(io.Discard, nil)), |
| 420 | ReportLogger: slog.New(slog.NewJSONHandler(&rig.reports, nil)), |
| 421 | }) |
| 422 | if err != nil { |
| 423 | t.Fatalf("calls.NewForTest: %v", err) |
| 424 | } |
| 425 | t.Cleanup(ctl.ShutdownForTest) // stops the sign-in mail worker too |
| 426 | // Served through rastrillo's production stack, built from the same |
| 427 | // calls.ServeOptions main hands to rastrillo.Serve: the security |
| 428 | // headers and the CSP a deployed instance sends, so a style attribute |
| 429 | // or script the policy refuses fails the gate (call.mjs reports every |
| 430 | // violation) instead of passing against a bare mux that sends none. |
| 431 | h, closeH, err := rastrillo.Handler(calls.ServeOptions(rastrillo.Options{Logger: slog.New(slog.NewTextHandler(io.Discard, nil))}, mux, ctl.Runtime())) |
| 432 | if err != nil { |
| 433 | t.Fatalf("rastrillo.Handler: %v", err) |
| 434 | } |
| 435 | t.Cleanup(func() { _ = closeH() }) |
| 436 | srv := &http.Server{Handler: h} |
| 437 | go func() { _ = srv.Serve(ln) }() |
| 438 | |
| 439 | rig.mu.Lock() |
| 440 | rig.ln, rig.srv, rig.ctl = ln, srv, ctl |
| 441 | want := rig.relay |
| 442 | rig.mu.Unlock() |
| 443 | |
| 444 | // A relay the app was not started with, handed to it the way a |
| 445 | // platform would have (spec §5.1's contract, through the same parser |
| 446 | // production reads $CARLOS_RELAY with). The value is the test vector |
| 447 | // every Go test in this package uses; the host in it does not exist, |
| 448 | // which is the point — ICE has to succeed on host candidates anyway. |
| 449 | if want { |
| 450 | if err := ctl.SetRelay(browserRelayContract()); err != nil { |
| 451 | t.Fatalf("SetRelay: %v", err) |
| 452 | } |
| 453 | } |
| 454 | } |
| 455 | |
| 456 | // wantRelay says whether the app this rig serves has a relay. It takes |
| 457 | // effect on the next serve, which is the restart every scenario gets |
| 458 | // before it starts and the one the restart control verb runs. |
| 459 | func (rig *browserRig) wantRelay(on bool) { |
| 460 | rig.mu.Lock() |
| 461 | rig.relay = on |
| 462 | rig.mu.Unlock() |
| 463 | } |
| 464 | |
| 465 | // browserRelayContract is the platform vector: one region, a bare stun |
| 466 | // URL and a turn URL at a host that resolves to nothing, the 32-byte key |
| 467 | // and the four-part username suffix. Built here rather than shared with |
| 468 | // ice_test.go's helper because that one takes a *testing.T and this is |
| 469 | // called from serve, where a marshalling failure of a literal would be a |
| 470 | // programming error and nothing else. |
| 471 | func browserRelayContract() string { |
| 472 | b, err := json.Marshal([]map[string]any{{ |
| 473 | "region": "eu-west-1", |
| 474 | "urls": []string{ |
| 475 | "stun:relay.eu-west-1.oncarlos.com:3478", |
| 476 | "turn:relay.eu-west-1.oncarlos.com:3478?transport=udp", |
| 477 | }, |
| 478 | "key": vectorKey, |
| 479 | "username_suffix": "abc:meet:0123456789abcdef:k1", |
| 480 | }}) |
| 481 | if err != nil { |
| 482 | panic("browser relay contract: " + err.Error()) |
| 483 | } |
| 484 | return base64.StdEncoding.EncodeToString(b) |
| 485 | } |
| 486 | |
| 487 | // stop is the SIGTERM and the socket close, in that order. Close does |
| 488 | // not wait for handlers — it shuts the listener and every connection at |
| 489 | // once — but cancelling the app's context first is what a real SIGTERM |
| 490 | // does, and it is the only thing that lets a live stream handler return |
| 491 | // through its own `case <-a.done` instead of having its socket pulled |
| 492 | // out from under it mid-write. |
| 493 | func (rig *browserRig) stop() { |
| 494 | rig.mu.Lock() |
| 495 | srv, ctl := rig.srv, rig.ctl |
| 496 | rig.mu.Unlock() |
| 497 | if ctl != nil { |
| 498 | ctl.ShutdownForTest() |
| 499 | } |
| 500 | if srv != nil { |
| 501 | _ = srv.Close() |
| 502 | } |
| 503 | } |
| 504 | |
| 505 | // restart is what the restart scenario asks for, and what every other |
| 506 | // scenario gets for free before it starts: the process goes away and |
| 507 | // comes back on the same port, with a new hub and a new boot id, over |
| 508 | // the same database. |
| 509 | func (rig *browserRig) restart(t *testing.T) { |
| 510 | t.Helper() |
| 511 | rig.stop() |
| 512 | |
| 513 | // SO_REUSEADDR is on by default for Go listeners, so the old |
| 514 | // connections' TIME_WAIT does not block the bind — but a listener |
| 515 | // closing is not instantaneous under load, so this is patient. |
| 516 | deadline := time.Now().Add(10 * time.Second) |
| 517 | for { |
| 518 | ln, err := net.Listen("tcp", rig.addr) |
| 519 | if err == nil { |
| 520 | rig.serve(t, ln) |
| 521 | return |
| 522 | } |
| 523 | if time.Now().After(deadline) { |
| 524 | t.Fatalf("restart: could not re-listen on %s: %v", rig.addr, err) |
| 525 | } |
| 526 | time.Sleep(50 * time.Millisecond) |
| 527 | } |
| 528 | } |
| 529 | |
| 530 | // signIn drives the real sign-in against the live listener and returns |
| 531 | // the session cookie's name and value. The name comes from the app, not |
| 532 | // from a constant here: rastrillo/sessions picks it from the origin's |
| 533 | // scheme (plain rastrillo_session on http, __Host- prefixed on https), |
| 534 | // and a gate that hardcoded one would quietly stop signing anything in |
| 535 | // the day this moves behind TLS. |
| 536 | func (rig *browserRig) signIn(t *testing.T, address string) (name, value string) { |
| 537 | t.Helper() |
| 538 | jar, err := cookiejar.New(nil) |
| 539 | if err != nil { |
| 540 | t.Fatalf("cookiejar: %v", err) |
| 541 | } |
| 542 | client := &http.Client{ |
| 543 | Jar: jar, |
| 544 | // The magic link answers 303; following it is what mints the |
| 545 | // session, so redirects are followed, but not endlessly. |
| 546 | CheckRedirect: func(r *http.Request, via []*http.Request) error { |
| 547 | if len(via) >= 5 { |
| 548 | return http.ErrUseLastResponse |
| 549 | } |
| 550 | return nil |
| 551 | }, |
| 552 | } |
| 553 | |
| 554 | before := rig.mail.count() |
| 555 | form := url.Values{"address": {address}} |
| 556 | req, err := http.NewRequest(http.MethodPost, rig.origin+"/signin", strings.NewReader(form.Encode())) |
| 557 | if err != nil { |
| 558 | t.Fatalf("build signin request: %v", err) |
| 559 | } |
| 560 | req.Header.Set("Content-Type", "application/x-www-form-urlencoded") |
| 561 | // The same-origin evidence csrf.Protect wants; a browser sends it on |
| 562 | // every form POST. |
| 563 | req.Header.Set("Origin", rig.origin) |
| 564 | res, err := client.Do(req) |
| 565 | if err != nil { |
| 566 | t.Fatalf("POST /signin: %v", err) |
| 567 | } |
| 568 | res.Body.Close() |
| 569 | |
| 570 | if rig.mail.count() == before { |
| 571 | t.Fatalf("no sign-in link was mailed to %s", address) |
| 572 | } |
| 573 | to, link := rig.mail.last() |
| 574 | if to != address || link == "" { |
| 575 | t.Fatalf("last mail went to %q, not %s", to, address) |
| 576 | } |
| 577 | |
| 578 | // Opening the link shows the confirm door and spends nothing; its |
| 579 | // one Sign in button POSTs the token back, and that signs in. |
| 580 | res, err = client.Get(link) |
| 581 | if err != nil { |
| 582 | t.Fatalf("open the sign-in link: %v", err) |
| 583 | } |
| 584 | page, _ := io.ReadAll(res.Body) |
| 585 | res.Body.Close() |
| 586 | m := confirmForm.FindSubmatch(page) |
| 587 | if res.StatusCode != http.StatusOK || m == nil { |
| 588 | t.Fatalf("the sign-in link answered %d without the confirm door", res.StatusCode) |
| 589 | } |
| 590 | confirm := url.Values{"token": {html.UnescapeString(string(m[2]))}} |
| 591 | req, err = http.NewRequest(http.MethodPost, rig.origin+html.UnescapeString(string(m[1])), strings.NewReader(confirm.Encode())) |
| 592 | if err != nil { |
| 593 | t.Fatalf("build confirm request: %v", err) |
| 594 | } |
| 595 | req.Header.Set("Content-Type", "application/x-www-form-urlencoded") |
| 596 | req.Header.Set("Origin", rig.origin) |
| 597 | res, err = client.Do(req) |
| 598 | if err != nil { |
| 599 | t.Fatalf("press Sign in on the confirm door: %v", err) |
| 600 | } |
| 601 | res.Body.Close() |
| 602 | |
| 603 | u, _ := url.Parse(rig.origin) |
| 604 | for _, c := range jar.Cookies(u) { |
| 605 | if strings.Contains(c.Name, "rastrillo_session") { |
| 606 | return c.Name, c.Value |
| 607 | } |
| 608 | } |
| 609 | t.Fatalf("following the sign-in link minted no session cookie (jar: %v)", jar.Cookies(u)) |
| 610 | return "", "" |
| 611 | } |
| 612 | |
| 613 | var sqidOnPage = regexp.MustCompile(`/m/([23456789a-z]{10})/join`) |
| 614 | var tokenOnPage = regexp.MustCompile(`/j/([A-Za-z0-9_-]{43})`) |
| 615 | |
| 616 | // enableWaitingRoom turns one meeting's waiting room on, as member A. |
| 617 | // |
| 618 | // It exists because the waiting room is no longer the default: meeting |
| 619 | // access defaults ship it off, so a guest following a link is admitted |
| 620 | // straight away and no admission queue is ever drawn. A scenario whose |
| 621 | // subject IS the queue has to ask for one, or it silently stops testing |
| 622 | // what it is named after — which is how the native gate's guest case came |
| 623 | // to wait thirty seconds for an Admit button that was never going to be |
| 624 | // there. |
| 625 | func (rig *browserRig) enableWaitingRoom(t *testing.T, sqid string) { |
| 626 | t.Helper() |
| 627 | req, err := http.NewRequest(http.MethodPost, rig.origin+"/meetings/"+sqid+"/settings", |
| 628 | strings.NewReader(url.Values{"waiting_room": {"on"}}.Encode())) |
| 629 | if err != nil { |
| 630 | t.Fatalf("build settings request: %v", err) |
| 631 | } |
| 632 | req.Header.Set("Content-Type", "application/x-www-form-urlencoded") |
| 633 | req.Header.Set("Origin", rig.origin) |
| 634 | req.AddCookie(&http.Cookie{Name: rig.cookieName, Value: rig.cookieA}) |
| 635 | // Not http.DefaultClient: it follows the 303 to the settings page and |
| 636 | // hands back that page's 200, so a refused save and an accepted one |
| 637 | // look identical. The redirect itself is the only honest evidence the |
| 638 | // handler accepted this. |
| 639 | client := &http.Client{CheckRedirect: func(*http.Request, []*http.Request) error { |
| 640 | return http.ErrUseLastResponse |
| 641 | }} |
| 642 | res, err := client.Do(req) |
| 643 | if err != nil { |
| 644 | t.Fatalf("POST meeting settings: %v", err) |
| 645 | } |
| 646 | defer res.Body.Close() |
| 647 | if res.StatusCode != http.StatusSeeOther { |
| 648 | body, _ := io.ReadAll(res.Body) |
| 649 | t.Fatalf("POST meeting settings: %d\n%s", res.StatusCode, body) |
| 650 | } |
| 651 | } |
| 652 | |
| 653 | // createMeeting is member A starting a call and reading the link off the |
| 654 | // page it is shown on exactly once. |
| 655 | func (rig *browserRig) createMeeting(t *testing.T) (sqid, token string) { |
| 656 | t.Helper() |
| 657 | req, err := http.NewRequest(http.MethodPost, rig.origin+"/meetings", |
| 658 | strings.NewReader(url.Values{"title": {"Board meeting"}}.Encode())) |
| 659 | if err != nil { |
| 660 | t.Fatalf("build create request: %v", err) |
| 661 | } |
| 662 | req.Header.Set("Content-Type", "application/x-www-form-urlencoded") |
| 663 | req.Header.Set("Origin", rig.origin) |
| 664 | req.AddCookie(&http.Cookie{Name: rig.cookieName, Value: rig.cookieA}) |
| 665 | |
| 666 | res, err := http.DefaultClient.Do(req) |
| 667 | if err != nil { |
| 668 | t.Fatalf("POST /meetings: %v", err) |
| 669 | } |
| 670 | defer res.Body.Close() |
| 671 | body, _ := io.ReadAll(res.Body) |
| 672 | if res.StatusCode != http.StatusOK { |
| 673 | t.Fatalf("POST /meetings: %d\n%s", res.StatusCode, body) |
| 674 | } |
| 675 | s := sqidOnPage.FindSubmatch(body) |
| 676 | k := tokenOnPage.FindSubmatch(body) |
| 677 | if s == nil || k == nil { |
| 678 | t.Fatalf("no meeting id or link on the page:\n%s", body) |
| 679 | } |
| 680 | return string(s[1]), string(k[1]) |
| 681 | } |
| 682 | |
| 683 | // run drives one scenario. node's stdout is read a line at a time so a |
| 684 | // CONTROL request is answered while the browser is still waiting on it; |
| 685 | // everything else is logged as it arrives, which is what makes a hung |
| 686 | // scenario readable rather than silent for three minutes. |
| 687 | func (rig *browserRig) run(t *testing.T, scenario, sqid, token string) { |
| 688 | t.Helper() |
| 689 | |
| 690 | ctx, cancel := context.WithTimeout(context.Background(), scenarioTimeout) |
| 691 | |
| 692 | cmd := exec.CommandContext(ctx, "node", "test/browser/call.mjs", |
| 693 | rig.origin, sqid, scenario) |
| 694 | cmd.Dir = repoRootForBrowser(t) |
| 695 | // The session cookies and the join-link token go in the environment, |
| 696 | // never on argv: a command line is readable by every process on the |
| 697 | // box, and either one of these is enough to be somebody in this |
| 698 | // meeting. |
| 699 | cmd.Env = append(os.Environ(), |
| 700 | "CALLS_COOKIE_NAME="+rig.cookieName, |
| 701 | "CALLS_COOKIE_A="+rig.cookieA, |
| 702 | "CALLS_COOKIE_B="+rig.cookieB, |
| 703 | "CALLS_JOIN_TOKEN="+token, |
| 704 | ) |
| 705 | |
| 706 | stdout, err := cmd.StdoutPipe() |
| 707 | if err != nil { |
| 708 | t.Fatalf("stdout pipe: %v", err) |
| 709 | } |
| 710 | stdin, err := cmd.StdinPipe() |
| 711 | if err != nil { |
| 712 | t.Fatalf("stdin pipe: %v", err) |
| 713 | } |
| 714 | var errs bytes.Buffer |
| 715 | cmd.Stderr = &errs |
| 716 | |
| 717 | if err := cmd.Start(); err != nil { |
| 718 | cancel() |
| 719 | t.Fatalf("start node: %v", err) |
| 720 | } |
| 721 | |
| 722 | // Every path out of here reaps node, including the ones that do not |
| 723 | // come back: rig.control calls t.Fatalf, which unwinds this |
| 724 | // goroutine, and without this the browser would outlive the test. |
| 725 | // Cancel first, so a hung node is killed rather than waited on. |
| 726 | var waitErr error |
| 727 | waited := false |
| 728 | wait := func() error { |
| 729 | if !waited { |
| 730 | waited = true |
| 731 | waitErr = cmd.Wait() |
| 732 | } |
| 733 | return waitErr |
| 734 | } |
| 735 | defer func() { |
| 736 | cancel() |
| 737 | _ = wait() |
| 738 | }() |
| 739 | |
| 740 | scanner := bufio.NewScanner(stdout) |
| 741 | scanner.Buffer(make([]byte, 0, 64<<10), 4<<20) |
| 742 | for scanner.Scan() { |
| 743 | line := scanner.Text() |
| 744 | if !strings.HasPrefix(line, "CONTROL ") { |
| 745 | t.Logf(" %s", line) |
| 746 | continue |
| 747 | } |
| 748 | verb := strings.TrimSpace(strings.TrimPrefix(line, "CONTROL ")) |
| 749 | t.Logf(" [control] %s", verb) |
| 750 | fmt.Fprintln(stdin, rig.control(t, verb)) |
| 751 | } |
| 752 | _ = stdin.Close() |
| 753 | |
| 754 | err = wait() |
| 755 | if s := strings.TrimSpace(errs.String()); s != "" { |
| 756 | t.Logf("node stderr:\n%s", s) |
| 757 | } |
| 758 | if err != nil { |
| 759 | t.Fatalf("the %s scenario failed: %v", scenario, err) |
| 760 | } |
| 761 | } |
| 762 | |
| 763 | // control answers one request from the browser side. Both verbs need |
| 764 | // something only this process has: the mail recorder, and the app's own |
| 765 | // lifecycle. |
| 766 | func (rig *browserRig) control(t *testing.T, verb string) string { |
| 767 | t.Helper() |
| 768 | switch { |
| 769 | case verb == "restart": |
| 770 | rig.restart(t) |
| 771 | return "ok" |
| 772 | case verb == "drop-member-b": |
| 773 | // The team changes, and the tick that notices is run by hand: |
| 774 | // only this process holds the allowlist and the hub, and the |
| 775 | // browser has no way to reach either (spec §2.4). |
| 776 | rig.mu.Lock() |
| 777 | ctl := rig.ctl |
| 778 | rig.mu.Unlock() |
| 779 | ctl.SetAllowlist(memberA) |
| 780 | ctl.TickForTest() |
| 781 | return "ok" |
| 782 | case strings.HasPrefix(verb, "guest-link "): |
| 783 | address := strings.TrimSpace(strings.TrimPrefix(verb, "guest-link ")) |
| 784 | // The browser has just posted the sign-in form; the link is in |
| 785 | // the recorder by the time the POST's response came back, but a |
| 786 | // short wait costs nothing and turns a race into a wait. |
| 787 | deadline := time.Now().Add(10 * time.Second) |
| 788 | for { |
| 789 | to, link := rig.mail.last() |
| 790 | if to == address && link != "" { |
| 791 | return link |
| 792 | } |
| 793 | if time.Now().After(deadline) { |
| 794 | t.Fatalf("no sign-in link was mailed to %s (last went to %q)", address, to) |
| 795 | } |
| 796 | time.Sleep(50 * time.Millisecond) |
| 797 | } |
| 798 | case strings.HasPrefix(verb, "quality-check "): |
| 799 | return rig.qualityCheck(strings.Fields(strings.TrimPrefix(verb, "quality-check "))) |
| 800 | case strings.HasPrefix(verb, "problem-check "): |
| 801 | fields := strings.Fields(strings.TrimPrefix(verb, "problem-check ")) |
| 802 | if len(fields) < 1 { |
| 803 | return "FAIL problem-check needs a reference" |
| 804 | } |
| 805 | return rig.problemCheck(fields[0], fields[1:]) |
| 806 | case verb == "quality-final": |
| 807 | for _, l := range rig.reports.linesFrom(rig.reportsFrom, "calls: quality") { |
| 808 | if l["final"] == true { |
| 809 | return "ok" |
| 810 | } |
| 811 | } |
| 812 | return "FAIL no quality report with final:true" |
| 813 | default: |
| 814 | t.Fatalf("unknown control verb from the browser: %q", verb) |
| 815 | return "" |
| 816 | } |
| 817 | } |
| 818 | |
| 819 | // qualityCheck answers the quality scenario (spec §15.26): the two |
| 820 | // browsers' automatic reports reached the log as `calls: quality` lines |
| 821 | // under one call tag and two different peer tags, each naming the other |
| 822 | // by its tag, and the log as a whole names nobody. `peers` is the two |
| 823 | // browsers' peer ids, which the log must not contain either. The answer |
| 824 | // is "ok", or "FAIL" and why, for call.mjs to print as its check. |
| 825 | func (rig *browserRig) qualityCheck(peers []string) string { |
| 826 | lines := rig.reports.linesFrom(rig.reportsFrom, "calls: quality") |
| 827 | if len(lines) < 2 { |
| 828 | return fmt.Sprintf("FAIL %d calls: quality lines, want at least 2", len(lines)) |
| 829 | } |
| 830 | calls := map[string]bool{} |
| 831 | tags := map[string]bool{} |
| 832 | named := map[string]bool{} |
| 833 | for _, l := range lines { |
| 834 | call, _ := l["call"].(string) |
| 835 | peer, _ := l["peer"].(string) |
| 836 | if call == "" || peer == "" { |
| 837 | return fmt.Sprintf("FAIL a quality line without its tags: %v", l) |
| 838 | } |
| 839 | if l["app"] != "web" { |
| 840 | return fmt.Sprintf("FAIL a quality line from app %v", l["app"]) |
| 841 | } |
| 842 | calls[call] = true |
| 843 | tags[peer] = true |
| 844 | report, _ := l["report"].(map[string]any) |
| 845 | ps, _ := report["peers"].([]any) |
| 846 | for _, p := range ps { |
| 847 | if m, ok := p.(map[string]any); ok { |
| 848 | if tag, ok := m["peer"].(string); ok { |
| 849 | named[tag] = true |
| 850 | } |
| 851 | } |
| 852 | } |
| 853 | } |
| 854 | if len(calls) != 1 { |
| 855 | return fmt.Sprintf("FAIL quality lines under %d call tags, want one: %v", len(calls), calls) |
| 856 | } |
| 857 | if len(tags) != 2 { |
| 858 | return fmt.Sprintf("FAIL quality lines under %d peer tags, want two: %v", len(tags), tags) |
| 859 | } |
| 860 | for tag := range tags { |
| 861 | if !named[tag] { |
| 862 | return fmt.Sprintf("FAIL no report names peer tag %s as a remote peer (named: %v)", tag, named) |
| 863 | } |
| 864 | } |
| 865 | if why := rig.leaks(peers); why != "" { |
| 866 | return "FAIL " + why |
| 867 | } |
| 868 | return "ok" |
| 869 | } |
| 870 | |
| 871 | // problemCheck answers "Report a problem": a `calls: problem report` |
| 872 | // line under the reference the sheet showed, at least one diagnostics |
| 873 | // line under it, and still nobody named anywhere in the log. |
| 874 | func (rig *browserRig) problemCheck(ref string, peers []string) string { |
| 875 | var head map[string]any |
| 876 | for _, l := range rig.reports.linesFrom(rig.reportsFrom, "calls: problem report") { |
| 877 | if l["ref"] == ref { |
| 878 | head = l |
| 879 | } |
| 880 | } |
| 881 | if head == nil { |
| 882 | return "FAIL no calls: problem report line with ref " + ref |
| 883 | } |
| 884 | parts := 0 |
| 885 | for _, l := range rig.reports.linesFrom(rig.reportsFrom, "calls: problem report diagnostics") { |
| 886 | if l["ref"] == ref { |
| 887 | parts++ |
| 888 | } |
| 889 | } |
| 890 | if parts == 0 { |
| 891 | return "FAIL no calls: problem report diagnostics line with ref " + ref |
| 892 | } |
| 893 | if why := rig.leaks(peers); why != "" { |
| 894 | return "FAIL " + why |
| 895 | } |
| 896 | return fmt.Sprintf("ok (note %q, %d diagnostics part(s), live %v)", head["note"], parts, head["live"]) |
| 897 | } |
| 898 | |
| 899 | // leaks is what the report log must never hold (spec §15.26): the two |
| 900 | // members' addresses and display names, the meeting's sqid and link, |
| 901 | // and any peer id of the call, in full or as the six characters the |
| 902 | // diagnostics name people by. "" when it holds none of them. |
| 903 | func (rig *browserRig) leaks(peers []string) string { |
| 904 | raw := rig.reports.raw() |
| 905 | forbidden := []string{memberA, memberB, rig.sqid, rig.token} |
| 906 | for _, p := range peers { |
| 907 | forbidden = append(forbidden, p) |
| 908 | // The six-character prefix only when it has a letter in it: six |
| 909 | // decimal digits are as likely to be a packet count as a person. |
| 910 | if len(p) >= 6 && strings.ContainsAny(p[:6], "abcdef") { |
| 911 | forbidden = append(forbidden, p[:6]) |
| 912 | } |
| 913 | } |
| 914 | for _, f := range forbidden { |
| 915 | if f != "" && strings.Contains(raw, f) { |
| 916 | return fmt.Sprintf("the report log contains %q", f) |
| 917 | } |
| 918 | } |
| 919 | // A display name is the address up to the "@" (see memberA); as a |
| 920 | // word, so a random tag that happens to spell it is not a finding. |
| 921 | for _, addr := range []string{memberA, memberB} { |
| 922 | name := addr[:strings.Index(addr, "@")] |
| 923 | if regexp.MustCompile(`(?i)\b` + regexp.QuoteMeta(name) + `\b`).MatchString(raw) { |
| 924 | return fmt.Sprintf("the report log contains the name %q", name) |
| 925 | } |
| 926 | } |
| 927 | return "" |
| 928 | } |
| 929 | |
| 930 | // repoRootForBrowser finds the repository from this file's own path, |
| 931 | // never from the working directory: go test runs in the package |
| 932 | // directory and the node script is addressed from the root. |
| 933 | func repoRootForBrowser(t *testing.T) string { |
| 934 | t.Helper() |
| 935 | _, file, _, ok := runtime.Caller(0) |
| 936 | if !ok { |
| 937 | t.Fatal("runtime.Caller failed") |
| 938 | } |
| 939 | return filepath.Dir(filepath.Dir(filepath.Dir(file))) |
| 940 | } |
| 941 | |
amadan