amadan
Calls: report tests, quality-summary helper, spec 15.26 and PRODUCT ruling, operations doc
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
10 files changed,
+1597
−3
PRODUCT.md+26 −2cmd/quality-summary/main.go+485 −0cmd/quality-summary/main_test.go+74 −0docs/operations/quality.md+103 −0docs/superpowers/specs/2026-09-07-meet-design.md+190 −0internal/calls/hub/report_test.go+82 −0internal/callstest/harness_test.go+11 −0internal/callstest/quality_test.go+603 −0native/README.md+22 −0protocol/quality.go+1 −1
diff --git a/PRODUCT.md b/PRODUCT.md| index 19dcc51..0abffa2 100644 |
| --- a/PRODUCT.md |
| +++ b/PRODUCT.md |
| @@ -49,7 +49,9 @@ in-call chat, and never a frame of media" (§0.1) — falsifiable: publish |
| the SQLite file, its WAL, and every log line, and the worst anyone |
| learns is the shape of the team's meetings and who minted what, never a |
| title, chat text, or signalling payload, enforced by a WAL-grep test and |
| -a captured-logger test, not merely asserted (§0.1). |
| +a captured-logger test, not merely asserted (§0.1). Since 2026-10-03 the log also |
| +holds quality and problem reports under random tags (§15.26): the shape of |
| +a call's connections, never which meeting or who. |
| ## Positioning |
| @@ -100,6 +102,25 @@ a captured-logger test, not merely asserted (§0.1). |
| `pending_joins` (a keyed address fingerprint, never plaintext), |
| `guest_grants`, `agents` (a member's minted principal; the token |
| itself is never stored, only its SHA-256) (models.go; §2.1). |
| +- **Quality reports and "Report a problem" go to the log, by Paul's ruling |
| + of 2026-10-03** (spec §15.26), which knowingly bends "stores nothing |
| + about calls". Collected: every 30 s in a call and at leave, each client's |
| + connection numbers per remote peer (bitrate, loss, RTT, jitter, audio |
| + concealment and jitter buffer, video freezes and frames, frame size and |
| + fps, the encoder's limitation, screen recovery steps), the candidate types |
| + and transport of the path (host/srflx/relay, udp/tcp/tls), the notices |
| + shown (Reconnecting, can't hear you yet, no sound, sound blocked, screen |
| + stalled), app/browser/OS and their versions, and the *kind* of microphone |
| + and speaker (bluetooth, usb, built-in…); all under a random call tag and a |
| + random peer tag. When someone presses Send in "Report a problem": their |
| + note, and their call diagnostics, which include device names and, on the |
| + web, the user agent, with people as peer tags and the meeting scrubbed. |
| + Never: names, emails, meeting titles or sqids, peer ids, IP addresses, |
| + device names (in quality reports), chat, audio or video. Nothing goes to |
| + the database; the log is the only store, kept for the platform's log |
| + retention — seven days, or 50 MiB of compressed log per app per box, |
| + whichever is first. `CALLS_QUALITY_REPORTS=off` stops quality reports; a |
| + person can stop their own in Settings (apps) or the Devices panel (web). |
| ## Capabilities and Constraints |
| @@ -262,7 +283,10 @@ and this file does not assume it does. |
| `native/README.md`). |
| **No attendance claim, ever**: §0.3 says Calls does not record who was |
| in a call or for how long; an earlier revision implied one and the |
| - spec dropped the implication rather than building the model. |
| + spec dropped the implication rather than building the model. The |
| + quality reports of §15.26 show that a call under a random tag happened |
| + between two times with so many clients in it, for seven days; never |
| + which meeting or who. |
| --- |
diff --git a/cmd/quality-summary/main.go b/cmd/quality-summary/main.go| new file mode 100644 |
| index 0000000..e70288c |
| --- /dev/null |
| +++ b/cmd/quality-summary/main.go |
| @@ -0,0 +1,485 @@ |
| +// Command quality-summary reads Calls' quality and problem report lines |
| +// (spec §15.26) and prints what happened in each call: who was in it, by |
| +// peer tag and platform; for every direction between two people, the |
| +// worst loss, the worst round trip, the freezes and how much of the time |
| +// the media went through the relay; and the notices people saw, in order. |
| +// |
| +// It reads `carlos logs` output on standard input, or, with nothing piped |
| +// in, runs `carlos logs` itself: |
| +// |
| +// quality-summary --since 3h # every call in the last three hours |
| +// quality-summary --since 24h --at 15:40 # the call running at 15:40 (Europe/Dublin) |
| +// quality-summary --call 3k2jq7m4xw5zt6ab # one call, by its tag |
| +// quality-summary --problem K7Q2M9PD --since 24h # one problem report, diagnostics and all |
| +// carlos logs --app calls --account oficina --since 2h -n 5000 | quality-summary |
| +// |
| +// Nothing here knows a meeting, a person or a name: the lines carry none. |
| +package main |
| + |
| +import ( |
| + "bufio" |
| + "encoding/json" |
| + "errors" |
| + "flag" |
| + "fmt" |
| + "io" |
| + "os" |
| + "os/exec" |
| + "sort" |
| + "strings" |
| + "time" |
| + |
| + "amadan.net/oficina/calls/protocol" |
| +) |
| + |
| +func main() { |
| + if err := run(os.Args[1:], os.Stdin, os.Stdout); err != nil { |
| + fmt.Fprintln(os.Stderr, "quality-summary:", err) |
| + os.Exit(1) |
| + } |
| +} |
| + |
| +type options struct { |
| + since, app, account, at, call, problem, zone string |
| +} |
| + |
| +func run(args []string, stdin *os.File, out io.Writer) error { |
| + fs := flag.NewFlagSet("quality-summary", flag.ContinueOnError) |
| + var o options |
| + fs.StringVar(&o.since, "since", "2h", "how far back carlos logs reads (a duration, or RFC3339)") |
| + fs.StringVar(&o.app, "app", "calls", "the carlos app") |
| + fs.StringVar(&o.account, "account", "oficina", "the carlos account") |
| + fs.StringVar(&o.at, "at", "", "only the call(s) running at this time, HH:MM in --zone, today (or YYYY-MM-DD HH:MM)") |
| + fs.StringVar(&o.call, "call", "", "only the call with this tag") |
| + fs.StringVar(&o.problem, "problem", "", "print one problem report, by its reference, with its diagnostics") |
| + fs.StringVar(&o.zone, "zone", "Europe/Dublin", "the zone times are shown and --at is read in") |
| + if err := fs.Parse(args); err != nil { |
| + return err |
| + } |
| + loc, err := time.LoadLocation(o.zone) |
| + if err != nil { |
| + return err |
| + } |
| + var in io.Reader = stdin |
| + if st, err := stdin.Stat(); err == nil && st.Mode()&os.ModeCharDevice != 0 { |
| + cmd := exec.Command("carlos", "logs", "--app", o.app, "--account", o.account, "--since", o.since, |
| + "-n", "5000", "--grep", "^calls: (quality|problem report)") |
| + cmd.Stderr = os.Stderr |
| + b, err := cmd.Output() |
| + if err != nil { |
| + return fmt.Errorf("carlos logs: %w", err) |
| + } |
| + in = strings.NewReader(string(b)) |
| + } |
| + lines, err := parse(in) |
| + if err != nil { |
| + return err |
| + } |
| + if o.problem != "" { |
| + return printProblem(out, lines, strings.ToUpper(o.problem), loc) |
| + } |
| + calls := gather(lines) |
| + var at time.Time |
| + if o.at != "" { |
| + if at, err = parseAt(o.at, loc, time.Now()); err != nil { |
| + return err |
| + } |
| + } |
| + shown := 0 |
| + for _, c := range calls { |
| + if o.call != "" && c.tag != o.call { |
| + continue |
| + } |
| + // A report covers the thirty seconds before it. |
| + if !at.IsZero() && (at.Before(c.first.Add(-30*time.Second)) || at.After(c.last.Add(30*time.Second))) { |
| + continue |
| + } |
| + c.print(out, loc) |
| + shown++ |
| + } |
| + if shown == 0 { |
| + fmt.Fprintln(out, "No calls in these lines match. Try a longer --since; carlos keeps an app's logs for seven days.") |
| + } |
| + return nil |
| +} |
| + |
| +// parseAt reads "15:40" as today in loc, or "2026-10-03 15:40". |
| +func parseAt(s string, loc *time.Location, now time.Time) (time.Time, error) { |
| + if t, err := time.ParseInLocation("2006-01-02 15:04", s, loc); err == nil { |
| + return t, nil |
| + } |
| + t, err := time.ParseInLocation("15:04", s, loc) |
| + if err != nil { |
| + return time.Time{}, errors.New("--at wants HH:MM or YYYY-MM-DD HH:MM") |
| + } |
| + n := now.In(loc) |
| + return time.Date(n.Year(), n.Month(), n.Day(), t.Hour(), t.Minute(), 0, 0, loc), nil |
| +} |
| + |
| +// line is one report line, as the app wrote it. |
| +type line struct { |
| + Time time.Time `json:"time"` |
| + Msg string `json:"msg"` |
| + Call string `json:"call"` |
| + Peer string `json:"peer"` |
| + App string `json:"app"` |
| + Version string `json:"version"` |
| + Browser string `json:"browser"` |
| + BrowVer string `json:"browserVersion"` |
| + OS string `json:"os"` |
| + OSVer string `json:"osVersion"` |
| + Final bool `json:"final"` |
| + Ref string `json:"ref"` |
| + Note string `json:"note"` |
| + Live bool `json:"live"` |
| + Part int `json:"part"` |
| + Of int `json:"of"` |
| + Text string `json:"text"` |
| + Report struct { |
| + Seconds *float64 `json:"seconds"` |
| + Devices *protocol.Devices `json:"devices"` |
| + Events *protocol.CallEvents `json:"events"` |
| + Peers []protocol.PeerQuality `json:"peers"` |
| + } `json:"report"` |
| +} |
| + |
| +// parse takes every line that carries a report, whatever carlos put in |
| +// front of it: the JSON object starts at the first "{". |
| +func parse(r io.Reader) ([]line, error) { |
| + var out []line |
| + sc := bufio.NewScanner(r) |
| + sc.Buffer(make([]byte, 0, 64<<10), 1<<20) |
| + for sc.Scan() { |
| + s := sc.Text() |
| + i := strings.Index(s, `{"time"`) |
| + if i < 0 { |
| + continue |
| + } |
| + var l line |
| + if json.Unmarshal([]byte(s[i:]), &l) != nil || !strings.HasPrefix(l.Msg, "calls: ") { |
| + continue |
| + } |
| + out = append(out, l) |
| + } |
| + return out, sc.Err() |
| +} |
| + |
| +type person struct { |
| + tag, app, version, platform string |
| + devices string |
| + reports int |
| +} |
| + |
| +// direction is what one person received from another, over every window. |
| +type direction struct { |
| + windows, pathWindows, relayWindows int |
| + paths map[string]int |
| + worstLoss float64 |
| + worstLossOf string |
| + worstRTT float64 |
| + freezes, freezeSeconds float64 |
| + samples, concealed float64 |
| + cantHear float64 |
| + reconnecting float64 |
| + reconnectingSeconds float64 |
| + noSound, stalled, blocked int |
| + screenSteps float64 |
| +} |
| + |
| +type event struct { |
| + at time.Time |
| + text string |
| +} |
| + |
| +type call struct { |
| + tag string |
| + first, last time.Time |
| + people map[string]*person |
| + order []string |
| + dirs map[[2]string]*direction |
| + events []event |
| + problems []line |
| +} |
| + |
| +func gather(lines []line) []*call { |
| + byTag := map[string]*call{} |
| + var calls []*call |
| + for _, l := range lines { |
| + if l.Call == "" || l.Msg == "calls: problem report diagnostics" { |
| + continue |
| + } |
| + c := byTag[l.Call] |
| + if c == nil { |
| + c = &call{tag: l.Call, first: l.Time, last: l.Time, people: map[string]*person{}, dirs: map[[2]string]*direction{}} |
| + byTag[l.Call] = c |
| + calls = append(calls, c) |
| + } |
| + if l.Time.Before(c.first) { |
| + c.first = l.Time |
| + } |
| + if l.Time.After(c.last) { |
| + c.last = l.Time |
| + } |
| + p := c.person(l) |
| + switch l.Msg { |
| + case "calls: problem report": |
| + c.problems = append(c.problems, l) |
| + case "calls: quality": |
| + c.addQuality(p, l) |
| + } |
| + } |
| + sort.Slice(calls, func(i, j int) bool { return calls[i].first.Before(calls[j].first) }) |
| + return calls |
| +} |
| + |
| +func (c *call) person(l line) *person { |
| + p := c.people[l.Peer] |
| + if p == nil { |
| + p = &person{tag: l.Peer} |
| + c.people[l.Peer] = p |
| + c.order = append(c.order, l.Peer) |
| + } |
| + // The quality lines say what the client is; a problem report's head |
| + // says it too, and fills in only for someone who sent no other line. |
| + if l.App != "" && (l.Msg == "calls: quality" || p.app == "") { |
| + p.app, p.version = l.App, l.Version |
| + switch { |
| + case l.Browser != "": |
| + p.platform = strings.TrimSpace(fmt.Sprintf("%s %s on %s %s", l.Browser, l.BrowVer, l.OS, l.OSVer)) |
| + case l.OS != "": |
| + p.platform = strings.TrimSpace(l.OS + " " + l.OSVer) |
| + } |
| + } |
| + return p |
| +} |
| + |
| +func val(p *float64) float64 { |
| + if p == nil { |
| + return 0 |
| + } |
| + return *p |
| +} |
| + |
| +func lossPct(packets, lost *float64) float64 { |
| + n, l := val(packets), val(lost) |
| + if n+l == 0 { |
| + return 0 |
| + } |
| + return 100 * l / (n + l) |
| +} |
| + |
| +func (c *call) addQuality(p *person, l line) { |
| + p.reports++ |
| + r := l.Report |
| + if r.Devices != nil { |
| + p.devices = fmt.Sprintf("input %s, output %s", orDash(r.Devices.Input), orDash(r.Devices.Output)) |
| + } |
| + if e := r.Events; e != nil { |
| + if val(e.Reconnecting) > 0 { |
| + c.events = append(c.events, event{l.Time, fmt.Sprintf("%s saw \"Reconnecting…\" for the whole call (%gx, %.1f s)", short(p.tag), val(e.Reconnecting), val(e.ReconnectingSeconds))}) |
| + } |
| + if e.AudioBlocked { |
| + c.events = append(c.events, event{l.Time, short(p.tag) + "'s browser blocked sound"}) |
| + } |
| + } |
| + for _, q := range r.Peers { |
| + key := [2]string{p.tag, string(q.Peer)} |
| + d := c.dirs[key] |
| + if d == nil { |
| + d = &direction{paths: map[string]int{}} |
| + c.dirs[key] = d |
| + } |
| + d.windows++ |
| + if q.Path != nil { |
| + d.pathWindows++ |
| + d.paths[fmt.Sprintf("%s→%s %s", orDash(q.Path.Local), orDash(q.Path.Remote), orDash(q.Path.Protocol))]++ |
| + if q.Path.Local == "relay" || q.Path.Remote == "relay" { |
| + d.relayWindows++ |
| + } |
| + } |
| + d.worstRTT = max(d.worstRTT, val(q.RTT)) |
| + if q.Out != nil { |
| + for _, o := range []*protocol.OutStream{q.Out.Audio, q.Out.Video, q.Out.Screen} { |
| + if o != nil { |
| + d.worstRTT = max(d.worstRTT, val(o.RTT)) |
| + } |
| + } |
| + if s := q.Out.Screen; s != nil { |
| + d.screenSteps += val(s.Rebuilds) + val(s.Reshares) + val(s.Failures) |
| + } |
| + } |
| + if in := q.In; in != nil { |
| + if a := in.Audio; a != nil { |
| + if x := lossPct(a.Packets, a.Lost); x > d.worstLoss { |
| + d.worstLoss, d.worstLossOf = x, "audio" |
| + } |
| + d.samples += val(a.Samples) |
| + d.concealed += val(a.Concealed) |
| + } |
| + for kind, v := range map[string]*protocol.InVideo{"video": in.Video, "screen": in.Screen} { |
| + if v == nil { |
| + continue |
| + } |
| + if x := lossPct(v.Packets, v.Lost); x > d.worstLoss { |
| + d.worstLoss, d.worstLossOf = x, kind |
| + } |
| + d.freezes += val(v.Freezes) |
| + d.freezeSeconds += val(v.FreezeSeconds) |
| + } |
| + } |
| + if e := q.Events; e != nil { |
| + d.cantHear += val(e.CantHearSeconds) |
| + d.reconnecting += val(e.Reconnecting) |
| + d.reconnectingSeconds += val(e.ReconnectingSeconds) |
| + var said []string |
| + if val(e.Reconnecting) > 0 { |
| + said = append(said, fmt.Sprintf("\"Reconnecting to %s…\" (%.1f s)", short(string(q.Peer)), val(e.ReconnectingSeconds))) |
| + } |
| + if val(e.CantHearSeconds) > 0 { |
| + said = append(said, fmt.Sprintf("\"%s can't hear you yet\" (%.1f s)", short(string(q.Peer)), val(e.CantHearSeconds))) |
| + } |
| + if e.NoSound { |
| + d.noSound++ |
| + said = append(said, "no sound from "+short(string(q.Peer))) |
| + } |
| + if e.NoSoundFromUs { |
| + said = append(said, short(string(q.Peer))+" said they get no sound from them") |
| + } |
| + if e.ScreenStalled { |
| + d.stalled++ |
| + said = append(said, short(string(q.Peer))+"'s screen stalled") |
| + } |
| + if e.AudioBlocked { |
| + d.blocked++ |
| + said = append(said, short(string(q.Peer))+"'s browser blocks sound") |
| + } |
| + if len(said) > 0 { |
| + c.events = append(c.events, event{l.Time, short(p.tag) + ": " + strings.Join(said, "; ")}) |
| + } |
| + } |
| + } |
| + if l.Final { |
| + c.events = append(c.events, event{l.Time, short(p.tag) + " left (final report)"}) |
| + } |
| +} |
| + |
| +func orDash(s string) string { |
| + if s == "" { |
| + return "-" |
| + } |
| + return s |
| +} |
| + |
| +// short is a tag as the summary prints it: six characters are plenty to |
| +// tell four people apart, and the full tag is in --call's output header. |
| +func short(tag string) string { |
| + if len(tag) > 6 { |
| + return tag[:6] |
| + } |
| + return tag |
| +} |
| + |
| +func (c *call) print(out io.Writer, loc *time.Location) { |
| + f, l := c.first.In(loc), c.last.In(loc) |
| + fmt.Fprintf(out, "Call %s %s – %s %s (%s), %d people, %d problem report(s)\n", |
| + c.tag, f.Format("2006-01-02 15:04:05"), l.Format("15:04:05"), loc, l.Sub(f).Round(time.Second), len(c.people), len(c.problems)) |
| + fmt.Fprintln(out, " People") |
| + for _, tag := range c.order { |
| + p := c.people[tag] |
| + fmt.Fprintf(out, " %s %s %s %s %d reports", short(tag), orDash(p.app), p.version, p.platform, p.reports) |
| + if p.devices != "" { |
| + fmt.Fprintf(out, " (%s)", p.devices) |
| + } |
| + fmt.Fprintln(out) |
| + } |
| + if len(c.dirs) > 0 { |
| + fmt.Fprintln(out, " Connections (what the first heard from the second)") |
| + keys := make([][2]string, 0, len(c.dirs)) |
| + for k := range c.dirs { |
| + keys = append(keys, k) |
| + } |
| + sort.Slice(keys, func(i, j int) bool { return keys[i][0]+keys[i][1] < keys[j][0]+keys[j][1] }) |
| + for _, k := range keys { |
| + d := c.dirs[k] |
| + path, n := "", 0 |
| + for p, m := range d.paths { |
| + if m > n || (m == n && p < path) { |
| + path, n = p, m |
| + } |
| + } |
| + relay := "-" |
| + if d.pathWindows > 0 { |
| + relay = fmt.Sprintf("%.0f%%", 100*float64(d.relayWindows)/float64(d.pathWindows)) |
| + } |
| + fmt.Fprintf(out, " %s ← %s worst loss %.1f%%%s, worst RTT %.0f ms, freezes %g (%.1f s)", |
| + short(k[0]), short(k[1]), d.worstLoss, ofWhat(d.worstLossOf), d.worstRTT, d.freezes, d.freezeSeconds) |
| + if d.samples > 0 { |
| + fmt.Fprintf(out, ", audio concealed %.2f%%", 100*d.concealed/d.samples) |
| + } |
| + fmt.Fprintf(out, ", path %s, relay %s", orDash(path), relay) |
| + if d.screenSteps > 0 { |
| + fmt.Fprintf(out, ", screen recovery steps %g", d.screenSteps) |
| + } |
| + fmt.Fprintln(out) |
| + } |
| + } |
| + if len(c.events) > 0 { |
| + fmt.Fprintln(out, " Events") |
| + sort.SliceStable(c.events, func(i, j int) bool { return c.events[i].at.Before(c.events[j].at) }) |
| + for _, e := range c.events { |
| + fmt.Fprintf(out, " %s %s\n", e.at.In(loc).Format("15:04:05"), e.text) |
| + } |
| + } |
| + for _, p := range c.problems { |
| + note := p.Note |
| + if note == "" { |
| + note = "(no note)" |
| + } |
| + fmt.Fprintf(out, " Problem %s at %s from %s (%s): %q\n quality-summary --problem %s --since <far enough back>\n", |
| + p.Ref, p.Time.In(loc).Format("15:04:05"), short(p.Peer), p.App, note, p.Ref) |
| + } |
| + fmt.Fprintln(out) |
| +} |
| + |
| +func ofWhat(kind string) string { |
| + if kind == "" { |
| + return "" |
| + } |
| + return " (" + kind + ")" |
| +} |
| + |
| +func printProblem(out io.Writer, lines []line, ref string, loc *time.Location) error { |
| + var head *line |
| + parts := map[int]string{} |
| + of := 0 |
| + for i := range lines { |
| + l := &lines[i] |
| + if l.Ref != ref { |
| + continue |
| + } |
| + switch l.Msg { |
| + case "calls: problem report": |
| + head = l |
| + case "calls: problem report diagnostics": |
| + parts[l.Part] = l.Text |
| + of = l.Of |
| + } |
| + } |
| + if head == nil { |
| + return fmt.Errorf("no problem report %s in these lines (try a longer --since)", ref) |
| + } |
| + fmt.Fprintf(out, "Problem report %s, %s\n", ref, head.Time.In(loc).Format("2006-01-02 15:04:05 MST")) |
| + fmt.Fprintf(out, "call %s, peer %s, %s %s %s %s %s %s, live %v\n", head.Call, head.Peer, head.App, head.Version, |
| + head.Browser, head.BrowVer, head.OS, head.OSVer, head.Live) |
| + fmt.Fprintf(out, "note: %s\n\n", orDash(head.Note)) |
| + for i := 1; i <= of; i++ { |
| + t, ok := parts[i] |
| + if !ok { |
| + fmt.Fprintf(out, "\n[part %d of %d is missing]\n", i, of) |
| + continue |
| + } |
| + fmt.Fprint(out, t) |
| + } |
| + fmt.Fprintln(out) |
| + return nil |
| +} |
diff --git a/cmd/quality-summary/main_test.go b/cmd/quality-summary/main_test.go| new file mode 100644 |
| index 0000000..dab6cce |
| --- /dev/null |
| +++ b/cmd/quality-summary/main_test.go |
| @@ -0,0 +1,74 @@ |
| +package main |
| + |
| +import ( |
| + "bytes" |
| + "os" |
| + "path/filepath" |
| + "strings" |
| + "testing" |
| +) |
| + |
| +// fixture is carlos logs output as it prints it: its own prefix, then the |
| +// app's JSON line. Two people in one call, a call before it, a problem |
| +// report in two parts, and a text line the summary must skip. |
| +const fixture = `2026-10-03 14:39:30 [app] calls.bds.oncarlos.com time=2026-10-03T14:39:30.000Z level=INFO msg="rastrillo: serving" |
| +2026-10-03 14:40:00 [app] calls.bds.oncarlos.com {"time":"2026-10-03T14:40:00Z","level":"INFO","msg":"calls: quality","call":"oldcalloldcall22","peer":"zzzzzzzzzzzzzzzz","app":"web","seconds":30,"report":{"seconds":30}} |
| +2026-10-03 14:41:00 [app] calls.bds.oncarlos.com {"time":"2026-10-03T14:41:00Z","level":"INFO","msg":"calls: quality","call":"callcallcallcall","peer":"aaaaaaaaaaaaaaaa","app":"mac","version":"0.4.9","os":"macos","osVersion":"26.0.1","final":false,"seconds":30,"report":{"seconds":30,"devices":{"input":"bluetooth","output":"built-in"},"peers":[{"peer":"bbbbbbbbbbbbbbbb","path":{"local":"srflx","remote":"relay","protocol":"udp"},"rtt":48,"in":{"audio":{"packets":1490,"lost":10,"samples":1440000,"concealed":14400},"video":{"packets":900,"lost":100,"freezes":2,"freezeSeconds":1.5}},"events":{"reconnecting":1,"reconnectingSeconds":4.2}}]}} |
| +2026-10-03 14:41:05 [app] calls.bds.oncarlos.com {"time":"2026-10-03T14:41:05Z","level":"INFO","msg":"calls: quality","call":"callcallcallcall","peer":"bbbbbbbbbbbbbbbb","app":"web","version":"de04e2d","browser":"chrome","browserVersion":"141.0","os":"windows","osVersion":"10.0","seconds":30,"report":{"seconds":30,"peers":[{"peer":"aaaaaaaaaaaaaaaa","path":{"local":"relay","remote":"srflx","protocol":"tls"},"rtt":180,"in":{"audio":{"packets":1500,"lost":0}},"events":{"cantHearSeconds":3}}]}} |
| +2026-10-03 14:41:30 [app] calls.bds.oncarlos.com {"time":"2026-10-03T14:41:30Z","level":"INFO","msg":"calls: quality","call":"callcallcallcall","peer":"aaaaaaaaaaaaaaaa","app":"mac","version":"0.4.9","os":"macos","osVersion":"26.0.1","final":true,"seconds":30,"report":{"seconds":30,"peers":[{"peer":"bbbbbbbbbbbbbbbb","path":{"local":"host","remote":"host","protocol":"udp"},"rtt":20}]}} |
| +2026-10-03 14:41:20 [app] calls.bds.oncarlos.com {"time":"2026-10-03T14:41:20Z","level":"WARN","msg":"calls: problem report","ref":"K7Q2M9PD","call":"callcallcallcall","peer":"aaaaaaaaaaaaaaaa","app":"mac","version":"0.4.9","os":"macos","live":true,"note":"video froze","parts":2} |
| +2026-10-03 14:41:20 [app] calls.bds.oncarlos.com {"time":"2026-10-03T14:41:20Z","level":"WARN","msg":"calls: problem report diagnostics","ref":"K7Q2M9PD","call":"callcallcallcall","peer":"aaaaaaaaaaaaaaaa","part":2,"of":2,"text":"second half\n"} |
| +2026-10-03 14:41:20 [app] calls.bds.oncarlos.com {"time":"2026-10-03T14:41:20Z","level":"WARN","msg":"calls: problem report diagnostics","ref":"K7Q2M9PD","call":"callcallcallcall","peer":"aaaaaaaaaaaaaaaa","part":1,"of":2,"text":"first half, "} |
| +` |
| + |
| +func runOn(t *testing.T, args ...string) string { |
| + t.Helper() |
| + path := filepath.Join(t.TempDir(), "logs") |
| + if err := os.WriteFile(path, []byte(fixture), 0o600); err != nil { |
| + t.Fatal(err) |
| + } |
| + f, err := os.Open(path) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + defer f.Close() |
| + var out bytes.Buffer |
| + if err := run(append([]string{"--zone", "Europe/Dublin"}, args...), f, &out); err != nil { |
| + t.Fatal(err) |
| + } |
| + return out.String() |
| +} |
| + |
| +func TestSummaryOfOneCall(t *testing.T) { |
| + out := runOn(t, "--at", "2026-10-03 15:41") |
| + t.Log("\n" + out) |
| + for _, want := range []string{ |
| + "Call callcallcallcall 2026-10-03 15:41:00 – 15:41:30 Europe/Dublin (30s), 2 people, 1 problem report(s)", |
| + "aaaaaa mac 0.4.9 macos 26.0.1 2 reports (input bluetooth, output built-in)", |
| + "bbbbbb web de04e2d chrome 141.0 on windows 10.0 1 reports", |
| + "aaaaaa ← bbbbbb worst loss 10.0% (video), worst RTT 48 ms, freezes 2 (1.5 s), audio concealed 1.00%, path host→host udp", |
| + "relay 50%", |
| + "bbbbbb ← aaaaaa worst loss 0.0%, worst RTT 180 ms, freezes 0 (0.0 s), path relay→srflx tls, relay 100%", |
| + `15:41:00 aaaaaa: "Reconnecting to bbbbbb…" (4.2 s)`, |
| + `15:41:05 bbbbbb: "aaaaaa can't hear you yet" (3.0 s)`, |
| + "15:41:30 aaaaaa left (final report)", |
| + `Problem K7Q2M9PD at 15:41:20 from aaaaaa (mac): "video froze"`, |
| + } { |
| + if !strings.Contains(out, want) { |
| + t.Errorf("missing %q", want) |
| + } |
| + } |
| + if strings.Contains(out, "oldcall") { |
| + t.Error("--at showed a call that had ended by then") |
| + } |
| +} |
| + |
| +func TestSummaryByCallTagAndAProblemReport(t *testing.T) { |
| + if out := runOn(t, "--call", "oldcalloldcall22"); !strings.Contains(out, "Call oldcalloldcall22") || strings.Contains(out, "callcallcallcall") { |
| + t.Fatalf("--call:\n%s", out) |
| + } |
| + out := runOn(t, "--problem", "k7q2m9pd") |
| + if !strings.Contains(out, "note: video froze") || !strings.Contains(out, "first half, second half") { |
| + t.Fatalf("--problem:\n%s", out) |
| + } |
| +} |
diff --git a/docs/operations/quality.md b/docs/operations/quality.md| new file mode 100644 |
| index 0000000..d002152 |
| --- /dev/null |
| +++ b/docs/operations/quality.md |
| @@ -0,0 +1,103 @@ |
| +# Reading quality and problem reports |
| + |
| +What Calls logs about calls, and how to find it (spec §15.26, Paul's ruling |
| +of 2026-10-03). The log is the only place these live: nothing is in the |
| +database. CARLOS keeps an app's log for **seven days** (or 50 MiB of |
| +compressed log per app per box, whichever comes first), so look within the |
| +week. |
| + |
| +## The lines |
| + |
| +Both kinds are JSON lines, so `carlos logs --field k=v` can filter on their |
| +top-level members (it reads fields only from JSON lines; `--grep` matches the |
| +`msg` of a JSON line and nothing else). |
| + |
| +- `calls: quality` (INFO), one per client every 30 s in a call and one at |
| + leave (`final: true`). Top level: `call` (the call tag, shared by everyone |
| + in one call), `peer` (this participation's tag), `app` (web, mac, iphone, |
| + ipad), `version`, `browser`, `browserVersion`, `os`, `osVersion`, |
| + `final`, `seconds`, `remotes`, and the headlines `relay`, `maxLossPct`, |
| + `maxRtt`, `freezes`, `reconnecting`. `report` holds the rest: `devices` |
| + (kinds, never names), `events`, and `peers`, one per remote peer named by |
| + its tag, with `path`, `rtt`, `out`, `in` and `events`. |
| +- `calls: problem report` (WARN), when someone presses Send in Report a |
| + problem: `ref` (what they were shown), `call`, `peer`, the client fields, |
| + `live` (still in the call, or within ten minutes after), `note` and |
| + `parts`. |
| +- `calls: problem report diagnostics` (WARN): the diagnostics text in |
| + `parts` lines, each with `ref`, `part`, `of` and `text`. |
| + |
| +Tags are random. They cannot be turned back into a meeting or a person, and |
| +nothing else in the log can be matched to them. The way from "the call at |
| +15:40" to a tag is the time. |
| + |
| +## In the console |
| + |
| +The Carloku console's log view for the app (account `oficina`, app `calls`): |
| +filter the message for `calls: quality` or `calls: problem report`, then by |
| +`call` once you have a tag. |
| + |
| +## With carlos |
| + |
| + # Every report in the last two hours |
| + carlos logs --app calls --account oficina --since 2h -n 5000 --grep '^calls: (quality|problem report)' |
| + |
| + # One call, every line from every person in it |
| + carlos logs --app calls --account oficina --since 24h -n 5000 --field call=3k2jq7m4xw5zt6ab |
| + |
| + # A problem report someone quoted, with its diagnostics |
| + carlos logs --app calls --account oficina --since 7d -n 5000 --field ref=K7Q2M9PD |
| + |
| + # Every problem report this week |
| + carlos logs --app calls --account oficina --since 7d --grep '^calls: problem report$' |
| + |
| + # Reports from the Mac app, or from one version of it |
| + carlos logs --app calls --account oficina --since 24h --grep '^calls: quality$' --field app=mac |
| + carlos logs --app calls --account oficina --since 24h --grep '^calls: quality$' --field app=mac --field version=0.4.9 |
| + |
| + # Windows where media went through the relay |
| + carlos logs --app calls --account oficina --since 24h --grep '^calls: quality$' --field relay=true |
| + |
| + # A window of time, in UTC (carlos prints and reads UTC) |
| + carlos logs --app calls --account oficina --since 2026-10-03T14:30:00Z --until 2026-10-03T15:00:00Z --grep '^calls: quality$' |
| + |
| +`-n` is at most 5,000 lines; a 30-second cadence is about 120 lines an hour |
| +per person, so narrow `--since` for a busy week. |
| + |
| +## The summary |
| + |
| +`cmd/quality-summary` turns those lines into an account of each call: |
| + |
| + go run ./cmd/quality-summary --since 3h # every call in the last three hours |
| + go run ./cmd/quality-summary --since 24h --at 15:40 # the call at 15:40, Europe/Dublin, today |
| + go run ./cmd/quality-summary --call 3k2jq7m4xw5zt6ab --since 24h |
| + go run ./cmd/quality-summary --problem K7Q2M9PD --since 7d |
| + carlos logs --app calls --account oficina --since 2h -n 5000 | go run ./cmd/quality-summary |
| + |
| +With nothing piped in it runs `carlos logs` itself. It prints, per call: |
| + |
| + Call callcallcallcall 2026-10-03 15:41:00 – 15:41:30 Europe/Dublin (30s), 2 people, 1 problem report(s) |
| + People |
| + aaaaaa mac 0.4.9 macos 26.0.1 2 reports (input bluetooth, output built-in) |
| + bbbbbb web de04e2d chrome 141.0 on windows 10.0 1 reports |
| + Connections (what the first heard from the second) |
| + aaaaaa ← bbbbbb worst loss 10.0% (video), worst RTT 48 ms, freezes 2 (1.5 s), audio concealed 1.00%, path host→host udp, relay 50% |
| + bbbbbb ← aaaaaa worst loss 0.0%, worst RTT 180 ms, freezes 0 (0.0 s), path relay→srflx tls, relay 100% |
| + Events |
| + 15:41:00 aaaaaa: "Reconnecting to bbbbbb…" (4.2 s) |
| + 15:41:05 bbbbbb: "aaaaaa can't hear you yet" (3.0 s) |
| + 15:41:30 aaaaaa left (final report) |
| + Problem K7Q2M9PD at 15:41:20 from aaaaaa (mac): "video froze" |
| + |
| +"Worst loss" is the worst 30-second window's inbound packet loss, of audio, |
| +camera or screen; "relay" is the share of windows whose path went through the |
| +relay; "audio concealed" is the share of received audio the receiver had to |
| +make up. |
| + |
| +## Turning it off |
| + |
| +`carlos env set --app calls --account oficina CALLS_QUALITY_REPORTS=off`, |
| +then `carlos restart` (which drops live calls), stops the automatic reports: |
| +the endpoint answers 204 and clients stop sending for that call. Report a |
| +problem keeps working. `carlos env unset --app calls --account oficina |
| +CALLS_QUALITY_REPORTS` and a restart turn them back on. |
diff --git a/docs/superpowers/specs/2026-09-07-meet-design.md b/docs/superpowers/specs/2026-09-07-meet-design.md| index fd2dc66..5e665b1 100644 |
| --- a/docs/superpowers/specs/2026-09-07-meet-design.md |
| +++ b/docs/superpowers/specs/2026-09-07-meet-design.md |
| @@ -81,6 +81,15 @@ message and an error path, and grep the capture for the title, the chat |
| text, any SDP fragment, any candidate address and any link token. A |
| link token appears once in an HTTP response body and nowhere else. |
| +**2026-10-03 (§15.26):** the log now also carries connection-quality |
| +reports and, when someone presses Send, problem reports, by Paul's ruling. |
| +Publish every log line and the worst anyone also learns is that some call, |
| +under a random tag, had so many participations on these platforms with this |
| +loss and these notices between these times — never which meeting, who was in |
| +it, or what was said, except whatever a person types into a problem report's |
| +note, and the device names a problem report's diagnostics carry. Nothing about |
| +a call is stored in the database. §15.26 has the exact list. |
| + |
| What the claim does not cover, said plainly: signalling passes through |
| Meet's process in plaintext for the instant it is relayed, plus a |
| replay ring of at most thirty-two targeted messages per participation |
| @@ -131,6 +140,9 @@ for the signalling transport (§4.1). |
| - No attendance record. Meet does not store who was in a call or for |
| how long. Revision 1 implied one and had no model for it; revision 2 |
| drops the implication rather than adding the model. |
| + Since §15.26 (2026-10-03) the log shows that a call, under a random tag, |
| + took place between two times with so many clients in it; never which |
| + meeting or who. |
| --- |
| @@ -218,6 +230,10 @@ Rooms, peers, admission, chat and presence live in the hub (§4.2) and |
| die with the process. A process restart empties every room; §4.5 says |
| what browsers do about it. |
| +Still nothing at rest in the database. Since 2026-10-03 the app's log is a |
| +store of its own for quality and problem reports, under random tags, kept for |
| +the platform's log retention (seven days); §15.26. |
| + |
| ### 2.3 Standing: who may enter |
| A person's **standing** toward a meeting is one of `member`, `guest` |
| @@ -2708,3 +2724,177 @@ the browser session's own standing, a guest still limited to their meeting. |
| `OpenLink` asks `/info` before answering a `/m/` address, so an app session |
| without standing is told so (`noAccess`) instead of failing at the join. |
| + |
| +### 15.26 §0.1, §0.3, §2.2, §4.4 — quality reports and "Report a problem" (2026-10-03) |
| + |
| +**The ruling.** Paul, 2026-10-03, approved both parts below, explicitly |
| +accepting that the second bends §0.1's "nothing kept" and §2.2's "nothing |
| +else at rest": the problems people have had in calls (§15.20 to §15.24) have |
| +each been found from a screenshot and a pasted diagnostics block, after the |
| +fact, and the calls that went wrong without anyone saying so were never found |
| +at all. Calls now writes connection-quality facts to its own log. It still |
| +stores nothing about a call in its database, and the log is the only store. |
| + |
| +**A. "Report a problem".** A button in the call's ⋯ More menu and in the |
| +ⓘ/Devices panel beside Copy call diagnostics, and on the screen a call ends |
| +on, on Mac, iPhone and the web, guests included. It opens a sheet with an |
| +optional "What went wrong?" (at most 1,000 characters) and the disclosure |
| +"Sends this call's connection diagnostics to the Calls server log. No audio or |
| +video." Send posts `POST /m/{sqid}/problem` with the note and the text Copy |
| +call diagnostics would copy, with one change: the people in the call are |
| +written "peer" and six characters of their peer id, not their names. The |
| +answer is a reference, eight characters of Crockford's alphabet (forty random |
| +bits), which the sheet shows under "Sent — thank you" so the reference can be |
| +looked up. The server logs one `calls: problem report` line (WARN: the |
| +reference, the tags below, the client, the note, and how many parts follow) |
| +and the diagnostics as `calls: problem report diagnostics` lines of at most |
| +6,000 escaped bytes each (`part`/`of`), because the platform keeps 8 KB of a |
| +log line and truncates the rest. Before logging, it scrubs the text of every |
| +peer id the call has held, in full and as the six-character prefix, writing |
| +`peer:<tag>` instead, and of the meeting's sqid, writing `[meeting]`. **Device |
| +names stay in the diagnostics** (a Scarlett, AirPods): they are what audio |
| +problems are found by, and the person chose to send them. The note is free |
| +text and is logged as typed. Not switched off by the kill switch below: it is |
| +a person asking. |
| + |
| +**B. Automatic quality reports.** Every thirty seconds while a client is |
| +admitted, and once more (`final`) at leave or end, each client posts `POST |
| +/m/{sqid}/quality`: a fixed schema (`protocol/quality.go`, version 1) of |
| +numbers and enums, per remote peer (the mesh has one connection per peer, so |
| +outbound is per peer too): |
| + |
| +- *out*, per audio, camera and screen: kbps, packets, and the receiver's own |
| + account of them (remote-inbound): lost, RTT, jitter; the encoder's |
| + `qualityLimitationReason` (none, cpu, bandwidth, other); frame size and fps; |
| + and §15.22's screen recovery steps toward that peer (keyframes, rebuilds, |
| + shares again, given up). |
| +- *in*: audio kbps, packets, lost, jitter, samples, concealed, inserted and |
| + removed samples, and the jitter buffer's mean delay; camera and screen |
| + kbps, packets, lost, jitter, freezes and their duration where the stack |
| + reports them, frames decoded and dropped, frame size and fps, and §15.22's |
| + pictures handed to their view again. |
| +- *path*: the selected candidate pair's two candidate types (host, srflx, |
| + prflx, relay) and its transport (udp, tcp, or tls for a relay over TLS), |
| + and its RTT. Never an address or a port. |
| +- *events* in the window: "Reconnecting to …" (§15.23) shown, how often and |
| + for how long; "… can't hear you yet" (§15.24), for how long; whether this |
| + client listed them in `noSoundFrom`, whether they listed this client, |
| + whether they reported `audioBlocked`, whether their screen was reported |
| + stalled here (§15.20, §15.21). For the whole call: the call-wide |
| + "Reconnecting…" and this client's own blocked sound. |
| +- *client*: app (web, mac, iphone, ipad), its version (the server's build |
| + for the web), browser and its version (web), OS and its version — enums |
| + and digits, never a user agent string or a device model. |
| +- *devices*: the kind of microphone and speaker, by transport (built-in, |
| + bluetooth, usb, wired, airplay, virtual, continuity, other, none, |
| + unknown). Never a device's name: "Paul's AirPods Pro" is a name. |
| + |
| +Counts are what happened in the window. Every number is optional, finite, |
| +non-negative and under a ceiling (`protocol/quality.go`: a window at most |
| +600 s, a delay at most 600,000 ms, a count at most 10⁹, a bitrate at most 10⁶ |
| +kbit/s, a frame at most 16,384 px, 240 fps); every string is one of its |
| +enums or a version of digits and dots; at most four remote peers (the mesh |
| +holds three) and a 16 KB body. Anything else is 400. A member the schema does |
| +not name is tolerated and dropped, so a newer client's addition does not fail |
| +an older server, and never reaches the log: the line is re-encoded from what |
| +was validated, numbers rounded to a tenth. The server writes one `calls: |
| +quality` line per report (INFO), a JSON object whose top level is what |
| +`carlos logs --field` can filter on — `call`, `peer`, `app`, `version`, |
| +`browser`, `browserVersion`, `os`, `osVersion`, `final`, `seconds`, |
| +`remotes`, and four headlines: `relay` (any path through the relay), |
| +`maxLossPct` (worst inbound loss), `maxRtt`, `freezes`, `reconnecting` — and |
| +whose `report` member is the rest, with each remote peer named by its peer |
| +tag. The largest report the schema allows fits in one platform line, which a |
| +test holds. A web page's or an app's own toggle ("Send anonymous quality |
| +reports", on by default; localStorage on the web, the apps' Settings) stops |
| +its reports; Report a problem stays. |
| + |
| +**The tags.** The **call tag** is minted by the hub, at random, when a |
| +participation opens in a room that holds none, and every participation until |
| +the room is empty again shares it: one call, one tag, however many people come |
| +and go, and a new tag for the room's next call. The **peer tag** is minted at |
| +random per participation. Neither is derived from anything — not the sqid, |
| +the peer id, the person, the session — and neither is ever logged beside any |
| +of them, so a line cannot be walked back to a meeting or a person through the |
| +log: §4.4's refusal lines carry the sqid and the peer id, and a report line |
| +carries neither. A report names a remote peer by the id its client knows; the |
| +server logs that peer's tag in its place, from the call's own table (at most |
| +64 participations a call; past that, `unknown`). The tags live in the hub and |
| +die with the process. |
| + |
| +**Authority.** The hub hands each participation a report token, sixteen |
| +random bytes, in its `hello` (and the same token in a resumed stream's |
| +hello). A client sends it in `X-Calls-Report`. It is honoured for the session |
| +it was given to and the room it was given for, while the participation lives |
| +and for ten minutes after it ends — any ending: leave, removal, the meeting |
| +ending, a lapsed resume — so the final report and a Report a problem from the |
| +screen the call ended on are taken. Anything else is 404, before the body is |
| +read. The token table is bounded (4,096 grants; past that the grant that ended |
| +longest ago goes, never a live one) and swept on the tick. Rate limits, keyed |
| +on the peer tag: a quality report every ten seconds with a burst of six, a |
| +problem report a minute with a burst of three; 429 with `Retry-After`. Bodies |
| +are refused past their caps (16 KB, 64 KB) without being read further. |
| + |
| +**The kill switch.** `CALLS_QUALITY_REPORTS=off` in the app's environment: |
| +`/quality` answers 204 before it looks at anything, the boot log says |
| +"calls: quality reports off", and a client answered 204 sends nothing more for |
| +that call. Default on. An old client sends nothing; a new client against an |
| +old server is answered 404 by the router, and its reports are lost, which is |
| +all that happens. |
| + |
| +**Where it goes, and for how long.** The app's stderr, as JSON lines (the |
| +platform reads fields only from a line that is a JSON object; every other |
| +line the app writes stays text). CARLOS ships an app's log to its deployment |
| +bucket every ten seconds and keeps it **seven days, or 50 MiB of compressed |
| +log per app per box, whichever comes first** (`carlos/platform` |
| +`internal/host/logship.go`: `logshipMaxAge`, `logshipMaxBytes`, at platform |
| +main `fe2088e3`, 2026-10-02), pruned an hour at a time. There is no archive |
| +beyond that. The box's own journal also sees the lines (journald capped at |
| +256 MB, host-wide, not readable through `carlos logs`). The platform's `edge` |
| +stream is reserved and writes nothing, client addresses included; Calls adds |
| +no address to any line, and cannot speak for logs outside the platform. |
| + |
| +**What is collected, and what is not.** |
| + |
| +| | Quality report | Problem report | |
| +|---|---|---| |
| +| When | every 30 s in a call, and at leave | when someone presses Send | |
| +| Who | every client, guests included, unless its toggle is off or the server's kill switch is | the person who pressed it | |
| +| Numbers about the connections (above) | yes | yes, in the diagnostics' own words | |
| +| Call tag, peer tag | yes | yes | |
| +| App, version, browser, OS and their versions | yes | yes, and the browser's user agent string in the web's diagnostics | |
| +| Kind of microphone and speaker | yes | — | |
| +| Device names | **no** | **yes**, in the diagnostics | |
| +| What the person typed | — | **yes**, the note | |
| +| People's names | no | no (peer tags) — unless typed into the note | |
| +| Emails, the meeting's title or sqid, peer ids | no | no (scrubbed) — unless typed into the note | |
| +| IP addresses, ports, candidates | no | no | |
| +| Chat, audio, video, SDP | no | no | |
| +| The database | nothing | nothing | |
| + |
| +**What this does to §0.1 and §0.3.** §0.1's falsifiable claim gains a |
| +sentence: publish every log line and the worst anyone learns now also |
| +includes that *some* call, under a random tag, had so many participations, |
| +on these platforms, with this loss and these notices, between these times; |
| +not which meeting it was, nor who was in it, nor what they said — except |
| +what a person types into a problem report's note. §0.3's "no attendance |
| +record" stands for the database and for any record tied to a person or a |
| +meeting; the log's timestamps under random tags show that a call happened |
| +and how many clients took part, which is the bend Paul accepted. |
| + |
| +**Reading them.** `docs/operations/quality.md`, and `cmd/quality-summary`, |
| +which reads `carlos logs` and prints each call: who, by peer tag and |
| +platform; the worst loss, RTT and freezes for each direction between two |
| +people, and how much of it went through the relay; and the notices, in order. |
| + |
| +**Tests.** `internal/callstest/quality_test.go`: the line's shape and fields; |
| +one call tag shared, peer tags distinct, a remote peer logged by its tag; |
| +nothing of the sqid, the title, the addresses, the peer ids or the tokens in |
| +the log; every schema refusal; unknown members tolerated and not logged; the |
| +size caps; the largest report fitting one platform line; the token refused |
| +for another session, room or none; the after-leave window, ended meetings |
| +included, and its end; a resume keeping the token and an empty room starting |
| +a new call; both rate limits; the kill switch; a problem report's reference, |
| +parts and scrubbing. `hub/report_test.go`: the sweep and the bound. The |
| +browser gate's `quality` scenario and the native gate's check: real clients' |
| +lines in the log, a shared call tag, no names. |
diff --git a/internal/calls/hub/report_test.go b/internal/calls/hub/report_test.go| new file mode 100644 |
| index 0000000..8295921 |
| --- /dev/null |
| +++ b/internal/calls/hub/report_test.go |
| @@ -0,0 +1,82 @@ |
| +package hub |
| + |
| +import ( |
| + "strings" |
| + "testing" |
| + "time" |
| +) |
| + |
| +// Spec §15.26: the tags are random, a call's are shared, and a token is |
| +// good for its participation and ten minutes after, and is swept then. |
| +func TestReportTokensTagsAndTheAfterLeaveWindow(t *testing.T) { |
| + now := time.Date(2026, 10, 3, 15, 40, 0, 0, time.UTC) |
| + h := testHub(&now) |
| + a, _ := h.Open("r1", "sessA", 1, "Ann", KindMember) |
| + b, _ := h.Open("r1", "sessB", 2, "Bob", KindMember) |
| + if a.ReportToken == "" || a.ReportToken == b.ReportToken { |
| + t.Fatalf("tokens %q %q", a.ReportToken, b.ReportToken) |
| + } |
| + ra, ok := h.Reporter("r1", "sessA", a.ReportToken) |
| + rb, _ := h.Reporter("r1", "sessB", b.ReportToken) |
| + if !ok || !ra.Live || ra.CallTag != rb.CallTag || ra.PeerTag == rb.PeerTag || len(ra.CallTag) != 16 { |
| + t.Fatalf("reporters %+v %+v", ra, rb) |
| + } |
| + for _, tag := range []string{ra.CallTag, ra.PeerTag} { |
| + for _, s := range []string{"r1", "sessA", "Ann", string(a.Peer)} { |
| + if strings.Contains(tag, s) || strings.Contains(s, tag) { |
| + t.Fatalf("tag %q derived from %q", tag, s) |
| + } |
| + } |
| + } |
| + if ra.Peers[b.Peer] != rb.PeerTag { |
| + t.Fatalf("A's reporter maps B to %q, want %q", ra.Peers[b.Peer], rb.PeerTag) |
| + } |
| + if _, ok := h.Reporter("r1", "sessB", a.ReportToken); ok { |
| + t.Fatal("another session's token was honoured") |
| + } |
| + if _, ok := h.Reporter("r2", "sessA", a.ReportToken); ok { |
| + t.Fatal("a token was honoured for another room") |
| + } |
| + if err := h.Leave("r1", "sessA", a.Peer); err != nil { |
| + t.Fatal(err) |
| + } |
| + if r, ok := h.Reporter("r1", "sessA", a.ReportToken); !ok || r.Live { |
| + t.Fatalf("just after leaving: %+v %v, want an ended grant", r, ok) |
| + } |
| + now = now.Add(ReportAfterLeave + time.Second) |
| + h.Tick(testCtx) |
| + h.mu.Lock() |
| + _, kept := h.reports[a.ReportToken] |
| + n := len(h.reports) |
| + h.mu.Unlock() |
| + if kept || n != 1 { |
| + t.Fatalf("after the window: kept %v, %d grants, want A's swept and B's live one left", kept, n) |
| + } |
| +} |
| + |
| +// The token table is bounded: past maxReportGrants the grant that ended |
| +// longest ago goes first, and a live one never does. |
| +func TestReportGrantsAreBounded(t *testing.T) { |
| + now := time.Date(2026, 10, 3, 15, 40, 0, 0, time.UTC) |
| + h := testHub(&now) |
| + live, _ := h.Open("keep", "sessLive", 1, "Ann", KindMember) |
| + for i := 0; i < maxReportGrants+10; i++ { |
| + now = now.Add(time.Millisecond) |
| + res, err := h.Open("r1", "s", int64(i%3), "x", KindMember) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + if err := h.Leave("r1", "s", res.Peer); err != nil { |
| + t.Fatal(err) |
| + } |
| + } |
| + h.mu.Lock() |
| + n := len(h.reports) |
| + h.mu.Unlock() |
| + if n > maxReportGrants { |
| + t.Fatalf("%d grants, bound %d", n, maxReportGrants) |
| + } |
| + if _, ok := h.Reporter("keep", "sessLive", live.ReportToken); !ok { |
| + t.Fatal("a live participation's token was evicted") |
| + } |
| +} |
diff --git a/internal/callstest/harness_test.go b/internal/callstest/harness_test.go| index fc4aedf..a72510f 100644 |
| --- a/internal/callstest/harness_test.go |
| +++ b/internal/callstest/harness_test.go |
| @@ -218,6 +218,14 @@ func newHarness(t *testing.T, members ...string) *harness { |
| // fills those in whenever env is not development, rather than merely |
| // swapping Env on the development set. |
| func newHarnessWithLogger(t *testing.T, env string, logger *slog.Logger, members ...string) *harness { |
| + t.Helper() |
| + return newHarnessWith(t, env, logger, nil, members...) |
| +} |
| + |
| +// newHarnessWith is newHarnessWithLogger with a last word on the Config, |
| +// for a test that needs a setting nothing else does (the report logger |
| +// and the quality kill switch of spec §15.26). |
| +func newHarnessWith(t *testing.T, env string, logger *slog.Logger, adjust func(*calls.Config), members ...string) *harness { |
| t.Helper() |
| dbPath := filepath.Join(t.TempDir(), "app.db") |
| d, err := db.Open(dbPath, logger) |
| @@ -233,6 +241,9 @@ func newHarnessWithLogger(t *testing.T, env string, logger *slog.Logger, members |
| cfg.InstanceKey = "test-instance-key-not-a-real-secret" |
| cfg.DEK = "AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=" |
| } |
| + if adjust != nil { |
| + adjust(&cfg) |
| + } |
| mux, ctl, err := calls.NewForTest(d, cfg) |
| if err != nil { |
| t.Fatal(err) |
diff --git a/internal/callstest/quality_test.go b/internal/callstest/quality_test.go| new file mode 100644 |
| index 0000000..82255d8 |
| --- /dev/null |
| +++ b/internal/callstest/quality_test.go |
| @@ -0,0 +1,603 @@ |
| +package callstest |
| + |
| +import ( |
| + "bytes" |
| + "context" |
| + "encoding/json" |
| + "fmt" |
| + "io" |
| + "log/slog" |
| + "net/http" |
| + "regexp" |
| + "strings" |
| + "sync" |
| + "testing" |
| + "time" |
| + |
| + "amadan.net/oficina/calls/internal/calls" |
| + "amadan.net/oficina/calls/protocol" |
| +) |
| + |
| +// Spec §15.26: quality and problem reports. These tests hold the ruling's |
| +// lines: what is logged, under which tags, and what never is; who may |
| +// report, and for how long; the bounds; the kill switch. |
| + |
| +const ( |
| + reportA = "paul@example.com" |
| + reportB = "ana@example.com" |
| + reportTitle = "Quarterly secrets review" |
| +) |
| + |
| +// syncBuffer is a log sink a stream goroutine and the test can share. |
| +type syncBuffer struct { |
| + mu sync.Mutex |
| + buf bytes.Buffer |
| +} |
| + |
| +func (b *syncBuffer) Write(p []byte) (int, error) { |
| + b.mu.Lock() |
| + defer b.mu.Unlock() |
| + return b.buf.Write(p) |
| +} |
| + |
| +func (b *syncBuffer) String() string { |
| + b.mu.Lock() |
| + defer b.mu.Unlock() |
| + return b.buf.String() |
| +} |
| + |
| +// lines are the JSON lines whose msg is msg. |
| +func (b *syncBuffer) lines(t *testing.T, msg string) []map[string]any { |
| + t.Helper() |
| + var out []map[string]any |
| + for _, line := range strings.Split(b.String(), "\n") { |
| + if strings.TrimSpace(line) == "" { |
| + continue |
| + } |
| + var m map[string]any |
| + if err := json.Unmarshal([]byte(line), &m); err != nil { |
| + t.Fatalf("a report line is not JSON: %v\n%s", err, line) |
| + } |
| + if m["msg"] == msg { |
| + out = append(out, m) |
| + } |
| + } |
| + return out |
| +} |
| + |
| +// reportRig is a meeting with two members in it, each joined, each |
| +// holding its report token; reports go to `reports` as JSON, as the |
| +// deployed main writes them, and everything else the app logs goes to |
| +// `app`. |
| +type reportRig struct { |
| + x *harness |
| + sqid string |
| + a, b *client |
| + sa, sb *sseReader |
| + peerA, peerB string |
| + tokA, tokB string |
| + reports *syncBuffer |
| + app *syncBuffer |
| +} |
| + |
| +func newReportRig(t *testing.T, quality string) *reportRig { |
| + t.Helper() |
| + reports, app := &syncBuffer{}, &syncBuffer{} |
| + x := newHarnessWith(t, calls.EnvDevelopment, slog.New(slog.NewTextHandler(app, &slog.HandlerOptions{Level: slog.LevelDebug})), func(c *calls.Config) { |
| + c.ReportLogger = slog.New(slog.NewJSONHandler(reports, nil)) |
| + c.QualityReports = quality |
| + }, reportA, reportB) |
| + a := newMemberBrowser(t, x, reportA) |
| + sqid, _ := createMeeting(t, a, reportTitle, "") |
| + b := newMemberBrowser(t, x, reportB) |
| + r := &reportRig{x: x, sqid: sqid, a: a, b: b, reports: reports, app: app} |
| + r.sa, r.peerA, r.tokA = r.enter(t, a) |
| + r.sb, r.peerB, r.tokB = r.enter(t, b) |
| + t.Cleanup(func() { r.sa.close(); r.sb.close() }) |
| + return r |
| +} |
| + |
| +// enter opens a stream, reads the hello's peer and report token, and |
| +// joins. |
| +func (r *reportRig) enter(t *testing.T, c *client) (*sseReader, string, string) { |
| + t.Helper() |
| + s := c.stream("/m/" + r.sqid + "/stream") |
| + peer, token := helloReport(t, s) |
| + if resp, _ := c.signal(r.sqid, peer, `{"type":"join"}`); resp.StatusCode != http.StatusOK { |
| + t.Fatalf("join: %d", resp.StatusCode) |
| + } |
| + return s, peer, token |
| +} |
| + |
| +func helloReport(t *testing.T, s *sseReader) (peer, token string) { |
| + t.Helper() |
| + name, data, ok := s.next(2 * time.Second) |
| + if !ok || name != "hello" { |
| + t.Fatalf("first event is %q, want hello", name) |
| + } |
| + var body struct{ Peer, Report string } |
| + if err := json.Unmarshal(data, &body); err != nil { |
| + t.Fatal(err) |
| + } |
| + if !regexp.MustCompile(`^[0-9a-f]{32}$`).MatchString(body.Report) { |
| + t.Fatalf("hello carries no report token: %s", data) |
| + } |
| + return body.Peer, body.Report |
| +} |
| + |
| +// report POSTs body to /m/{sqid}/{kind} with token. |
| +func (c *client) report(sqid, kind, token string, body []byte) (*http.Response, []byte) { |
| + c.t.Helper() |
| + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) |
| + defer cancel() |
| + req, err := http.NewRequestWithContext(ctx, http.MethodPost, c.x.server().URL+"/m/"+sqid+"/"+kind, bytes.NewReader(body)) |
| + if err != nil { |
| + c.t.Fatal(err) |
| + } |
| + for _, ck := range c.cookies { |
| + req.AddCookie(ck) |
| + } |
| + req.Header.Set("Content-Type", "application/json") |
| + req.Header.Set("Origin", testOrigin) |
| + if token != "" { |
| + req.Header.Set("X-Calls-Report", token) |
| + } |
| + resp, err := c.x.server().Client().Do(req) |
| + if err != nil { |
| + c.t.Fatalf("POST %s: %v", kind, err) |
| + } |
| + b, _ := io.ReadAll(resp.Body) |
| + resp.Body.Close() |
| + return resp, b |
| +} |
| + |
| +func num(v float64) *float64 { return &v } |
| + |
| +// sampleQuality is an honest report about one remote peer. |
| +func sampleQuality(remote string) protocol.QualityReport { |
| + return protocol.QualityReport{ |
| + V: 1, Seconds: num(30), |
| + Client: protocol.ReportClient{App: "mac", Version: "0.4.9", OS: "macos", OSVersion: "26.0.1"}, |
| + Devices: &protocol.Devices{Input: "bluetooth", Output: "built-in"}, |
| + Events: &protocol.CallEvents{Reconnecting: num(1), ReconnectingSeconds: num(4.2)}, |
| + Peers: []protocol.PeerQuality{{ |
| + Peer: protocol.PeerID(remote), |
| + Path: &protocol.Path{Local: "srflx", Remote: "relay", Protocol: "udp"}, |
| + RTT: num(48.25), |
| + Out: &protocol.Outbound{ |
| + Audio: &protocol.OutStream{Kbps: num(32), Packets: num(1500), Lost: num(3), RTT: num(50), Jitter: num(4)}, |
| + Video: &protocol.OutStream{Kbps: num(900), Limit: "bandwidth", Width: num(1280), Height: num(720), FPS: num(30)}, |
| + }, |
| + In: &protocol.Inbound{ |
| + Audio: &protocol.InAudio{Packets: num(1490), Lost: num(10), Concealed: num(4800), Samples: num(1440000), JitterBufferMs: num(62)}, |
| + Video: &protocol.InVideo{Packets: num(2700), Lost: num(300), Freezes: num(2), FreezeSeconds: num(1.5), Decoded: num(890), Dropped: num(4), Width: num(640), Height: num(360), FPS: num(29.7)}, |
| + }, |
| + Events: &protocol.PeerEvents{CantHearSeconds: num(2), NoSound: true}, |
| + }}, |
| + } |
| +} |
| + |
| +// forbidden is everything the ruling says a report line never carries: |
| +// the meeting, the people, their addresses and names, the peer ids that |
| +// the signalling log names, and the report tokens. |
| +func (r *reportRig) forbidden() []string { |
| + return []string{r.sqid, reportTitle, reportA, reportB, "example.com", r.peerA, r.peerB, r.tokA, r.tokB} |
| +} |
| + |
| +func (r *reportRig) assertClean(t *testing.T) { |
| + t.Helper() |
| + raw := r.reports.String() |
| + for _, f := range r.forbidden() { |
| + if strings.Contains(raw, f) { |
| + t.Errorf("the report log contains %q:\n%s", f, raw) |
| + } |
| + } |
| +} |
| + |
| +func TestQualityReportsShareACallTagAndNameNothing(t *testing.T) { |
| + r := newReportRig(t, "") |
| + resp, _ := r.a.report(r.sqid, "quality", r.tokA, mustJSON(t, sampleQuality(r.peerB))) |
| + if resp.StatusCode != http.StatusAccepted { |
| + t.Fatalf("A's report: %d, want 202", resp.StatusCode) |
| + } |
| + resp, _ = r.b.report(r.sqid, "quality", r.tokB, mustJSON(t, sampleQuality(r.peerA))) |
| + if resp.StatusCode != http.StatusAccepted { |
| + t.Fatalf("B's report: %d, want 202", resp.StatusCode) |
| + } |
| + lines := r.reports.lines(t, "calls: quality") |
| + if len(lines) != 2 { |
| + t.Fatalf("%d quality lines, want 2:\n%s", len(lines), r.reports.String()) |
| + } |
| + a, b := lines[0], lines[1] |
| + tag := regexp.MustCompile(`^[a-z2-7]{16}$`) |
| + for _, k := range []string{"call", "peer"} { |
| + for _, l := range lines { |
| + if s, _ := l[k].(string); !tag.MatchString(s) { |
| + t.Fatalf("%s tag %v is not a random tag", k, l[k]) |
| + } |
| + } |
| + } |
| + if a["call"] != b["call"] { |
| + t.Errorf("one call, two call tags: %v and %v", a["call"], b["call"]) |
| + } |
| + if a["peer"] == b["peer"] { |
| + t.Errorf("two participations, one peer tag %v", a["peer"]) |
| + } |
| + // A's report names B by B's tag, never B's id. |
| + rep := a["report"].(map[string]any) |
| + peers := rep["peers"].([]any) |
| + if got := peers[0].(map[string]any)["peer"]; got != b["peer"] { |
| + t.Errorf("A's report names its peer %v, want B's tag %v", got, b["peer"]) |
| + } |
| + // The line's shape: what carlos logs --field can filter on, at the |
| + // top, and the rest under report. |
| + for k, want := range map[string]any{"level": "INFO", "app": "mac", "version": "0.4.9", "os": "macos", "osVersion": "26.0.1", |
| + "final": false, "seconds": 30.0, "remotes": 1.0, "relay": true, "maxLossPct": 10.0, "maxRtt": 50.0, "freezes": 2.0, "reconnecting": 1.0} { |
| + if a[k] != want { |
| + t.Errorf("line[%q] = %v (%T), want %v", k, a[k], a[k], want) |
| + } |
| + } |
| + if got := peers[0].(map[string]any)["rtt"]; got != 48.3 { |
| + t.Errorf("rtt %v, want rounded to a tenth (48.3)", got) |
| + } |
| + if _, ok := rep["client"]; ok { |
| + t.Error("the client is logged twice: at the top and under report") |
| + } |
| + r.assertClean(t) |
| + // And the app's own log says nothing about an accepted report. |
| + if strings.Contains(r.app.String(), "quality") { |
| + t.Errorf("the app log mentions a quality report:\n%s", r.app.String()) |
| + } |
| +} |
| + |
| +func TestQualityReportSchemaIsStrict(t *testing.T) { |
| + r := newReportRig(t, "") |
| + base := func() map[string]any { |
| + var m map[string]any |
| + _ = json.Unmarshal(mustJSON(t, sampleQuality(r.peerB)), &m) |
| + return m |
| + } |
| + peer0 := func(m map[string]any) map[string]any { return m["peers"].([]any)[0].(map[string]any) } |
| + cases := map[string]func(m map[string]any){ |
| + "version 2": func(m map[string]any) { m["v"] = 2 }, |
| + "no seconds": func(m map[string]any) { delete(m, "seconds") }, |
| + "zero seconds": func(m map[string]any) { m["seconds"] = 0 }, |
| + "an hour": func(m map[string]any) { m["seconds"] = 3600 }, |
| + "unknown app": func(m map[string]any) { m["client"].(map[string]any)["app"] = "android" }, |
| + "no app": func(m map[string]any) { delete(m["client"].(map[string]any), "app") }, |
| + "a version with a space": func(m map[string]any) { m["client"].(map[string]any)["version"] = "0.4 beta" }, |
| + "a user agent": func(m map[string]any) { m["client"].(map[string]any)["osVersion"] = "Mozilla/5.0" }, |
| + "a device's name": func(m map[string]any) { m["devices"].(map[string]any)["input"] = "Paul's AirPods Pro" }, |
| + "a string for a number": func(m map[string]any) { peer0(m)["rtt"] = "48" }, |
| + "a negative count": func(m map[string]any) { peer0(m)["in"].(map[string]any)["audio"].(map[string]any)["lost"] = -1 }, |
| + "a huge count": func(m map[string]any) { peer0(m)["in"].(map[string]any)["audio"].(map[string]any)["samples"] = 1e12 }, |
| + "a minute's rtt and more": func(m map[string]any) { |
| + peer0(m)["rtt"] = 600001 |
| + }, |
| + "an address for a path": func(m map[string]any) { peer0(m)["path"].(map[string]any)["local"] = "192.168.1.4" }, |
| + "an unknown limit": func(m map[string]any) { |
| + peer0(m)["out"].(map[string]any)["video"].(map[string]any)["limit"] = "thermal" |
| + }, |
| + "a name for a peer": func(m map[string]any) { peer0(m)["peer"] = "Ana" }, |
| + "the same peer twice": func(m map[string]any) { m["peers"] = append(m["peers"].([]any), peer0(m)) }, |
| + "a peer list for a room": func(m map[string]any) { m["peers"] = "everyone" }, |
| + "five peers": func(m map[string]any) { |
| + var ps []any |
| + for i := 0; i <= protocol.MaxQualityPeers; i++ { |
| + ps = append(ps, map[string]any{"peer": fmt.Sprintf("%032x", i)}) |
| + } |
| + m["peers"] = ps |
| + }, |
| + } |
| + for name, spoil := range cases { |
| + m := base() |
| + spoil(m) |
| + r.x.advance(10 * time.Second) // one report's budget each |
| + resp, _ := r.a.report(r.sqid, "quality", r.tokA, mustJSON(t, m)) |
| + if resp.StatusCode != http.StatusBadRequest { |
| + t.Errorf("%s: %d, want 400", name, resp.StatusCode) |
| + } |
| + } |
| + if n := len(r.reports.lines(t, "calls: quality")); n != 0 { |
| + t.Fatalf("%d refused reports were logged", n) |
| + } |
| + |
| + // A member the schema does not name is tolerated, and not logged: |
| + // a newer client's field, or anything a client should never send. |
| + m := base() |
| + m["name"] = "Paul Campbell" |
| + m["client"].(map[string]any)["device"] = "Paul's MacBook Pro" |
| + peer0(m)["address"] = "203.0.113.9" |
| + peer0(m)["out"].(map[string]any)["audio"].(map[string]any)["codec"] = "opus" |
| + r.x.advance(10 * time.Second) |
| + if resp, _ := r.a.report(r.sqid, "quality", r.tokA, mustJSON(t, m)); resp.StatusCode != http.StatusAccepted { |
| + t.Fatalf("unknown members: %d, want 202", resp.StatusCode) |
| + } |
| + raw := r.reports.String() |
| + for _, f := range []string{"Paul Campbell", "MacBook", "203.0.113.9", "codec", "opus"} { |
| + if strings.Contains(raw, f) { |
| + t.Errorf("an unknown member reached the log: %q", f) |
| + } |
| + } |
| + |
| + // Past 16 KB the body is not read. |
| + big := base() |
| + big["padding"] = strings.Repeat("x", protocol.MaxQualityBody) |
| + r.x.advance(10 * time.Second) |
| + if resp, _ := r.a.report(r.sqid, "quality", r.tokA, mustJSON(t, big)); resp.StatusCode != http.StatusRequestEntityTooLarge { |
| + t.Errorf("a 16 KB report: %d, want 413", resp.StatusCode) |
| + } |
| + r.assertClean(t) |
| +} |
| + |
| +// The longest report the schema allows, every number at its ceiling and |
| +// every peer present, still fits in one platform log line: the platform |
| +// keeps 8 KB of a line and truncates the rest. |
| +func TestTheLargestQualityLineFitsThePlatformsLine(t *testing.T) { |
| + r := newReportRig(t, "") |
| + big := func() *float64 { return num(123456789.1) } |
| + ms := func() *float64 { return num(599999.9) } |
| + out := func() *protocol.OutStream { |
| + return &protocol.OutStream{Kbps: num(999999.9), Packets: big(), Lost: big(), RTT: ms(), Jitter: ms(), Limit: "bandwidth", |
| + Width: num(16384), Height: num(16384), FPS: num(240), Keyframes: big(), Rebuilds: big(), Reshares: big(), Failures: big()} |
| + } |
| + in := func() *protocol.InVideo { |
| + return &protocol.InVideo{Kbps: num(999999.9), Packets: big(), Lost: big(), Jitter: ms(), Freezes: big(), FreezeSeconds: num(599.9), |
| + Decoded: big(), Dropped: big(), Width: num(16384), Height: num(16384), FPS: num(240), Reattaches: big()} |
| + } |
| + q := sampleQuality(r.peerB) |
| + q.Peers = nil |
| + for i := 0; i < protocol.MaxQualityPeers; i++ { |
| + q.Peers = append(q.Peers, protocol.PeerQuality{ |
| + Peer: protocol.PeerID(fmt.Sprintf("%032x", i)), |
| + Path: &protocol.Path{Local: "unknown", Remote: "unknown", Protocol: "unknown"}, RTT: ms(), |
| + Out: &protocol.Outbound{Audio: out(), Video: out(), Screen: out()}, |
| + In: &protocol.Inbound{ |
| + Audio: &protocol.InAudio{Kbps: num(999999.9), Packets: big(), Lost: big(), Jitter: ms(), Samples: big(), Concealed: big(), Inserted: big(), Removed: big(), JitterBufferMs: ms()}, |
| + Video: in(), Screen: in(), |
| + }, |
| + Events: &protocol.PeerEvents{Reconnecting: big(), ReconnectingSeconds: num(599.9), CantHearSeconds: num(599.9), |
| + NoSound: true, NoSoundFromUs: true, AudioBlocked: true, ScreenStalled: true}, |
| + }) |
| + } |
| + if resp, _ := r.a.report(r.sqid, "quality", r.tokA, mustJSON(t, q)); resp.StatusCode != http.StatusAccepted { |
| + t.Fatalf("the largest report: %d", resp.StatusCode) |
| + } |
| + line := strings.TrimSpace(r.reports.String()) |
| + if n := len(line); n > 8192 { |
| + t.Fatalf("the largest quality line is %d bytes; the platform keeps 8192", n) |
| + } |
| +} |
| + |
| +func TestQualityReportsAreAuthorizedByTheTokenTheSessionAndTheRoom(t *testing.T) { |
| + r := newReportRig(t, "") |
| + body := mustJSON(t, sampleQuality(r.peerB)) |
| + other, _ := createMeeting(t, r.a, "another", "") |
| + for name, try := range map[string]func() *http.Response{ |
| + // Signed out never reaches the handler: the session middleware |
| + // refuses it first, which is a refusal all the same. |
| + "no token": func() *http.Response { resp, _ := r.a.report(r.sqid, "quality", "", body); return resp }, |
| + "a made-up token": func() *http.Response { |
| + resp, _ := r.a.report(r.sqid, "quality", strings.Repeat("0", 32), body) |
| + return resp |
| + }, |
| + "a token not hex": func() *http.Response { resp, _ := r.a.report(r.sqid, "quality", "Paul", body); return resp }, |
| + "B's token from A": func() *http.Response { resp, _ := r.a.report(r.sqid, "quality", r.tokB, body); return resp }, |
| + "another room": func() *http.Response { resp, _ := r.a.report(other, "quality", r.tokA, body); return resp }, |
| + "a room id not a room": func() *http.Response { resp, _ := r.a.report("not-a-room", "quality", r.tokA, body); return resp }, |
| + "signed out": func() *http.Response { |
| + c := r.x.browser(t) |
| + resp, _ := c.report(r.sqid, "quality", r.tokA, body) |
| + return resp |
| + }, |
| + } { |
| + resp := try() |
| + want := http.StatusNotFound |
| + if name == "signed out" { |
| + want = http.StatusForbidden |
| + } |
| + if resp.StatusCode != want { |
| + t.Errorf("%s: %d, want %d", name, resp.StatusCode, want) |
| + } |
| + } |
| + if n := len(r.reports.lines(t, "calls: quality")); n != 0 { |
| + t.Fatalf("%d unauthorized reports were logged", n) |
| + } |
| +} |
| + |
| +func TestReportsOutliveTheParticipationByTenMinutes(t *testing.T) { |
| + r := newReportRig(t, "") |
| + if resp, _ := r.a.signal(r.sqid, r.peerA, `{"type":"leave"}`); resp.StatusCode != http.StatusOK { |
| + t.Fatalf("leave: %d", resp.StatusCode) |
| + } |
| + final := sampleQuality(r.peerB) |
| + final.Final = true |
| + if resp, _ := r.a.report(r.sqid, "quality", r.tokA, mustJSON(t, final)); resp.StatusCode != http.StatusAccepted { |
| + t.Fatalf("the final report after leave: %d, want 202", resp.StatusCode) |
| + } |
| + r.x.advance(9 * time.Minute) |
| + resp, body := r.a.report(r.sqid, "problem", r.tokA, mustJSON(t, protocol.ProblemReport{Note: "it went quiet", Client: protocol.ReportClient{App: "web"}})) |
| + if resp.StatusCode != http.StatusOK { |
| + t.Fatalf("a problem report nine minutes after leaving: %d %s", resp.StatusCode, body) |
| + } |
| + lines := r.reports.lines(t, "calls: problem report") |
| + if len(lines) != 1 || lines[0]["live"] != false { |
| + t.Fatalf("problem lines %v, want one with live=false", lines) |
| + } |
| + r.x.advance(2 * time.Minute) |
| + resp, _ = r.a.report(r.sqid, "problem", r.tokA, mustJSON(t, protocol.ProblemReport{Client: protocol.ReportClient{App: "web"}})) |
| + if resp.StatusCode != http.StatusNotFound { |
| + t.Fatalf("eleven minutes after leaving: %d, want 404", resp.StatusCode) |
| + } |
| + // The ended meeting: B's token keeps working for the window too. |
| + if rec := r.a.post("/meetings/"+r.sqid+"/end", nil); rec.Code != http.StatusSeeOther { |
| + t.Fatalf("end: %d", rec.Code) |
| + } |
| + if resp, _ := r.b.report(r.sqid, "quality", r.tokB, mustJSON(t, final)); resp.StatusCode != http.StatusAccepted { |
| + t.Fatalf("a final report from an ended meeting: %d, want 202", resp.StatusCode) |
| + } |
| + r.assertClean(t) |
| +} |
| + |
| +func TestAResumeKeepsTheTokenAndAnEmptyRoomStartsANewCall(t *testing.T) { |
| + r := newReportRig(t, "") |
| + // A resumed stream's hello carries the same token. |
| + r.sa.close() |
| + s := r.a.stream("/m/" + r.sqid + "/stream?peer=" + r.peerA) |
| + peer, token := helloReport(t, s) |
| + if peer != r.peerA || token != r.tokA { |
| + t.Fatalf("resume: peer %s token %s, want the same participation's", peer, token) |
| + } |
| + s.close() |
| + callOf := func(c *client, token, remote string) string { |
| + t.Helper() |
| + if resp, _ := c.report(r.sqid, "quality", token, mustJSON(t, sampleQuality(remote))); resp.StatusCode != http.StatusAccepted { |
| + t.Fatalf("report: %d", resp.StatusCode) |
| + } |
| + lines := r.reports.lines(t, "calls: quality") |
| + return lines[len(lines)-1]["call"].(string) |
| + } |
| + first := callOf(r.a, r.tokA, r.peerB) |
| + for _, x := range []struct { |
| + c *client |
| + peer string |
| + }{{r.a, r.peerA}, {r.b, r.peerB}} { |
| + if resp, _ := x.c.signal(r.sqid, x.peer, `{"type":"leave"}`); resp.StatusCode != http.StatusOK { |
| + t.Fatalf("leave: %d", resp.StatusCode) |
| + } |
| + } |
| + r.sb.close() |
| + // Everyone has gone: the next person in starts a new call. |
| + _, peerA2, tokA2 := r.enter(t, r.a) |
| + second := callOf(r.a, tokA2, peerA2) |
| + if first == second { |
| + t.Fatalf("an empty room's next call kept the call tag %s", first) |
| + } |
| + // The old token still reports under the old call. |
| + if got := callOf(r.a, r.tokA, r.peerB); got != first { |
| + t.Fatalf("the first call's token reports under %s, want %s", got, first) |
| + } |
| +} |
| + |
| +func TestReportRateLimits(t *testing.T) { |
| + r := newReportRig(t, "") |
| + body := mustJSON(t, sampleQuality(r.peerB)) |
| + for i := 0; i < 6; i++ { |
| + if resp, _ := r.a.report(r.sqid, "quality", r.tokA, body); resp.StatusCode != http.StatusAccepted { |
| + t.Fatalf("quality report %d: %d, want 202 (burst six)", i+1, resp.StatusCode) |
| + } |
| + } |
| + resp, _ := r.a.report(r.sqid, "quality", r.tokA, body) |
| + if resp.StatusCode != http.StatusTooManyRequests || resp.Header.Get("Retry-After") == "" { |
| + t.Fatalf("the seventh at once: %d (Retry-After %q), want 429 with Retry-After", resp.StatusCode, resp.Header.Get("Retry-After")) |
| + } |
| + // Per participation: B's budget is its own. |
| + if resp, _ := r.b.report(r.sqid, "quality", r.tokB, mustJSON(t, sampleQuality(r.peerA))); resp.StatusCode != http.StatusAccepted { |
| + t.Fatalf("B, after A spent its budget: %d", resp.StatusCode) |
| + } |
| + r.x.advance(10 * time.Second) |
| + if resp, _ := r.a.report(r.sqid, "quality", r.tokA, body); resp.StatusCode != http.StatusAccepted { |
| + t.Fatalf("ten seconds later: %d, want 202", resp.StatusCode) |
| + } |
| + |
| + problem := mustJSON(t, protocol.ProblemReport{Note: "x", Client: protocol.ReportClient{App: "web"}}) |
| + for i := 0; i < 3; i++ { |
| + if resp, _ := r.a.report(r.sqid, "problem", r.tokA, problem); resp.StatusCode != http.StatusOK { |
| + t.Fatalf("problem report %d: %d", i+1, resp.StatusCode) |
| + } |
| + } |
| + if resp, _ := r.a.report(r.sqid, "problem", r.tokA, problem); resp.StatusCode != http.StatusTooManyRequests { |
| + t.Fatalf("the fourth problem report at once: %d, want 429", resp.StatusCode) |
| + } |
| +} |
| + |
| +func TestTheKillSwitchAnswers204AndLogsNothing(t *testing.T) { |
| + r := newReportRig(t, "off") |
| + for _, token := range []string{r.tokA, ""} { |
| + resp, _ := r.a.report(r.sqid, "quality", token, mustJSON(t, sampleQuality(r.peerB))) |
| + if resp.StatusCode != http.StatusNoContent { |
| + t.Fatalf("quality reports off (token %q): %d, want 204", token, resp.StatusCode) |
| + } |
| + } |
| + if n := len(r.reports.lines(t, "calls: quality")); n != 0 { |
| + t.Fatalf("%d quality lines with reports off", n) |
| + } |
| + // "Report a problem" is a person asking; it is not switched off. |
| + if resp, _ := r.a.report(r.sqid, "problem", r.tokA, mustJSON(t, protocol.ProblemReport{Client: protocol.ReportClient{App: "web"}})); resp.StatusCode != http.StatusOK { |
| + t.Fatalf("a problem report with quality reports off: %d, want 200", resp.StatusCode) |
| + } |
| + if !strings.Contains(r.app.String(), "quality reports off") { |
| + t.Error("boot did not say quality reports are off") |
| + } |
| +} |
| + |
| +func TestAProblemReportIsLoggedUnderItsReferenceAndScrubbed(t *testing.T) { |
| + r := newReportRig(t, "") |
| + // What a client sends: people as "peer" and six characters of their |
| + // id, and here also the full id and the meeting's address, which a |
| + // client could have in a log line it did not write. |
| + var diag strings.Builder |
| + diag.WriteString("Calls web diagnostics\n## Call\n") |
| + fmt.Fprintf(&diag, "peer %s: connection connected\nopened %s/m/%s\nfull id %s\n", r.peerB[:6], testOrigin, r.sqid, r.peerB) |
| + for diag.Len() < 20_000 { |
| + diag.WriteString("12:00:00.000 screen from " + r.peerB[:6] + " stalled here: \"packets\" <+0> — no packets arriving\n") |
| + } |
| + note := "Ana's video froze at 15:40 — " + strings.Repeat("é", 900) |
| + resp, body := r.a.report(r.sqid, "problem", r.tokA, mustJSON(t, protocol.ProblemReport{ |
| + Note: note, Diagnostics: diag.String(), |
| + Client: protocol.ReportClient{App: "web", Version: "de04e2d", Browser: "chrome", BrowserVersion: "141.0", OS: "macos", OSVersion: "10.15.7"}, |
| + })) |
| + if resp.StatusCode != http.StatusOK { |
| + t.Fatalf("problem: %d %s", resp.StatusCode, body) |
| + } |
| + var receipt protocol.ProblemReceipt |
| + if err := json.Unmarshal(body, &receipt); err != nil || !regexp.MustCompile(`^[0-9A-HJKMNP-TV-Z]{8}$`).MatchString(receipt.Ref) { |
| + t.Fatalf("receipt %s: want an eight-character reference", body) |
| + } |
| + heads := r.reports.lines(t, "calls: problem report") |
| + if len(heads) != 1 { |
| + t.Fatalf("%d problem report lines, want 1", len(heads)) |
| + } |
| + head := heads[0] |
| + if head["ref"] != receipt.Ref || head["note"] != note || head["level"] != "WARN" || head["live"] != true || head["browser"] != "chrome" { |
| + t.Fatalf("head line %v", head) |
| + } |
| + parts := r.reports.lines(t, "calls: problem report diagnostics") |
| + if len(parts) < 3 || float64(len(parts)) != head["parts"] { |
| + t.Fatalf("%d diagnostics lines, head says %v; want 20 KB in several", len(parts), head["parts"]) |
| + } |
| + var joined strings.Builder |
| + for i, p := range parts { |
| + if p["ref"] != receipt.Ref || p["part"] != float64(i+1) || p["of"] != float64(len(parts)) || p["call"] != head["call"] || p["peer"] != head["peer"] { |
| + t.Fatalf("part %d: %v", i+1, p) |
| + } |
| + joined.WriteString(p["text"].(string)) |
| + } |
| + for _, line := range strings.Split(r.reports.String(), "\n") { |
| + if len(line) > 8192 { |
| + t.Fatalf("a report line of %d bytes; the platform keeps 8192", len(line)) |
| + } |
| + } |
| + // B appears under B's tag, and the meeting as [meeting]. |
| + var tagB string |
| + if resp, _ := r.b.report(r.sqid, "quality", r.tokB, mustJSON(t, sampleQuality(r.peerA))); resp.StatusCode == http.StatusAccepted { |
| + ls := r.reports.lines(t, "calls: quality") |
| + tagB = ls[len(ls)-1]["peer"].(string) |
| + } |
| + text := joined.String() |
| + if !strings.Contains(text, "peer peer:"+tagB+": connection connected") || !strings.Contains(text, "full id peer:"+tagB) || !strings.Contains(text, "/m/[meeting]") { |
| + t.Fatalf("diagnostics not scrubbed to tags:\n%.400s", text) |
| + } |
| + if len(text) < 20_000 { |
| + t.Fatalf("the diagnostics came back %d bytes, want all of them", len(text)) |
| + } |
| + r.assertClean(t) |
| + |
| + // The bounds: a note over a thousand characters, a body over 64 KB. |
| + if resp, _ := r.a.report(r.sqid, "problem", r.tokA, mustJSON(t, protocol.ProblemReport{Note: strings.Repeat("a", 1001), Client: protocol.ReportClient{App: "web"}})); resp.StatusCode != http.StatusBadRequest { |
| + t.Errorf("a 1,001-character note: %d, want 400", resp.StatusCode) |
| + } |
| + if resp, _ := r.a.report(r.sqid, "problem", r.tokA, mustJSON(t, protocol.ProblemReport{Diagnostics: strings.Repeat("a", 65<<10), Client: protocol.ReportClient{App: "web"}})); resp.StatusCode != http.StatusRequestEntityTooLarge { |
| + t.Errorf("65 KB of diagnostics: %d, want 413", resp.StatusCode) |
| + } |
| +} |
diff --git a/native/README.md b/native/README.md| index 0405e19..ab7c49f 100644 |
| --- a/native/README.md |
| +++ b/native/README.md |
| @@ -707,6 +707,28 @@ Developer ID signing, notarization and App Store packaging remain follow-up work |
| The iPhone target, device builds and Safari tests are described in |
| [ios/README.md](ios/README.md). |
| +## Quality reports and Report a problem |
| + |
| +The apps send a connection-quality report every 30 seconds in a call and one |
| +at leave, and "Report a problem" (the ⋯ menu, the ⓘ panel, and the screen a |
| +call ends on) sends the call diagnostics with a note. Spec §15.26 says exactly |
| +what is in them and what never is; Settings has the disclosure and the |
| +"Send anonymous quality reports" switch. They land in the server's log as |
| +`calls: quality` and `calls: problem report` JSON lines under random call and |
| +peer tags, kept for the platform's seven days. To read them: |
| + |
| +```sh |
| +# The call at 15:40 today (Europe/Dublin), summarised |
| +go run ./cmd/quality-summary --since 24h --at 15:40 |
| +# A reference someone was shown, with its diagnostics |
| +go run ./cmd/quality-summary --problem K7Q2M9PD --since 7d |
| +# The raw lines of one call |
| +carlos logs --app calls --account oficina --since 24h -n 5000 --field call=<tag> |
| +``` |
| + |
| +[docs/operations/quality.md](../docs/operations/quality.md) has the line |
| +shapes, more queries, and the kill switch (`CALLS_QUALITY_REPORTS=off`). |
| + |
| ## Shared code |
| - `protocol/`: the server and client use the same Go wire types. The hub keeps |
diff --git a/protocol/quality.go b/protocol/quality.go| index db21780..1619aa4 100644 |
| --- a/protocol/quality.go |
| +++ b/protocol/quality.go |
| @@ -18,7 +18,7 @@ const QualityVersion = 1 |
| // Bounds the server enforces, here so a client can clamp to the same ones. |
| const ( |
| - MaxQualityPeers = 8 // remote peers in one report (the mesh holds three) |
| + MaxQualityPeers = 4 // remote peers in one report: the mesh holds three, and one spare for a connection on its way out |
| MaxQualitySeconds = 600 // a window, in seconds |
| MaxQualityMillis = 600_000 // any rtt, jitter or buffer delay, in ms |
| MaxQualityCount = 1e9 // any count of packets, frames or samples |