Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
37 changes: 37 additions & 0 deletions CHANGELOG.md
Original file line numberDiff line numberDiff line change
Expand Up@@ -10,6 +10,43 @@ Full module documentation: [hexdocs.pm/mob](https://hexdocs.pm/mob).

## [Unreleased]

### Added
- **`mix mob.flake`** — run the suite repeatedly and report which tests are not
deterministic. `--runs N`, `--until-failure`, `--keep-going`, `--seed`, and a
path to narrow the target. A flake does not announce itself; it fails once on
someone else's branch and the natural response is to re-run and move on. This
makes looking cheap and deliberate.

### Fixed
- **Test-suite races that made every automated verdict unreliable** (MOB-154,
MOB-119, MOB-123). A 1-in-20 flake corrupted a mutation-testing result and,
a day later, sent a bisect down the wrong path when it appeared in the same
run as a real failure.

`Mob.ComponentRegistry` is a globally-named singleton owning a named ETS
table, and two `async: true` modules each started it with
`start_supervised/1` — so whichever test won the race owned it, and ExUnit
tore it down while the other module was still using it. It now starts in
`test_helper.exs`, owned by the run.

Nineteen `on_exit(fn -> if Process.alive?(pid), do: GenServer.stop(pid) end)`
sites across eleven modules were check-then-act across a process boundary;
thirteen further modules had each written the same correct workaround
privately, byte for byte. All now use `Mob.Test.ProcessHelpers`, which gains
`stop_pid/2`, `await_exit/2` and `eventually/2`.

All 35 `Process.sleep` calls were classified rather than swept. Twelve are
`Process.sleep(:infinity)` — a parked stub, not a wait. Of the 23 finite
ones, 8 remain: three are the subject under test in `render_stats_test.exs`,
three are the backoff inside a poll loop that has its own deadline, one is a
`@doc` example, and one is a genuine bet that is recorded rather than
disguised. The other 15 either had nothing to wait for (a `GenServer.call`
from the same process is already an ordering barrier) or were replaced with
the actual barrier — a ready-message, `Logger.flush/0`, a monitor, or a
bounded poll. See
`decisions/2026-09-06-tests-wait-for-events-not-durations.md`.


### Changed
- **Input NIFs now run on a dirty IO scheduler.** `tap`, `tap_xy`,
`long_press_xy`, `swipe_xy`, `type_text`, `delete_backward` and `clear_text`
Expand Down
125 changes: 125 additions & 0 deletions decisions/2026-09-06-tests-wait-for-events-not-durations.md
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,125 @@
# Tests wait for events, not durations

Date: 2026-09-06
Status: accepted
Ticket: MOB-154 (with MOB-119, MOB-123)

## Context

A 1-in-20 flake corrupted a mutation-testing verdict, and a day later sent a
bisect down the wrong path: a real failure and a flake appeared in the same
run, and the flake was investigated first. That is the actual cost of a noisy
suite — not the red build, but the hours spent trusting it.

Three mechanisms were behind it.

**A globally-named singleton owned by whichever test started it.**
`Mob.ComponentRegistry` is named and owns a named ETS table. Two `async: true`
modules each called `start_supervised({Mob.ComponentRegistry, []})` and
tolerated `{:error, {:already_started, _}}`. Whichever test won the race owned
it, and ExUnit tore the process — and its table — down when that test ended,
while a concurrent test in the other module was still using it. The loser died
on `:ets.lookup` against a table that no longer existed.

**Check-then-act across a process boundary.** `on_exit(fn -> if
Process.alive?(pid), do: GenServer.stop(pid) end)` appeared 19 times across 11
modules.
Since MOB-112 the screen owner is linked to the test process, which ExUnit
exits with `:shutdown` at test end — so the owner is dying concurrently with
the callback trying to stop it. Thirteen more modules had each independently
written a correct private `stop_safely/1`, byte for byte identically, which is
a fair signal it belonged somewhere shared.

**Fixed durations standing in for synchronisation.** `Process.exit(pid, :kill)`
followed by `Process.sleep(10)` followed by an assertion that requires the
process to be gone.

## Decision

**A test waits for the event it depends on, never for a duration it hopes is
long enough.** `Process.monitor` plus a `:DOWN`, or `assert_receive`. A monitor
is not a tighter bet than a sleep — the `:DOWN` cannot arrive before the
process is gone, so there is nothing left to race.

Shared state that outlives a single test is owned by the **run**, not by
whichever test got there first. `Mob.ComponentRegistry` now starts in
`test_helper.exs`, so both setups take the `:already_started` branch, nobody
owns it, and nobody can tear it down mid-flight. Sharing is safe because every
entry is keyed by a per-test `screen_pid`.

`Mob.Test.ProcessHelpers` is where these live: `stop_if_running/2` (named),
`stop_pid/2` (pid), `await_exit/2` (block until actually gone, raising rather
than continuing on timeout — a helper that returns quietly on timeout leaves
the caller asserting against a live process, which is the situation being
avoided).

### Not every sleep is a bug

All 35 `Process.sleep` calls were classified rather than swept. Twelve were
`Process.sleep(:infinity)` — a stub process parked until something kills it,
not a wait at all. That left 23 finite sleeps, now 8:

**Removed because there was never anything to wait for (5).** A `GenServer.call`
from the same process that sent the earlier messages is already a barrier:
Erlang orders messages pairwise between two processes, so every `send` is ahead
of the `call` in the mailbox and has been handled before the reply comes back
(`event/integration_test.exs` ×3, `nav/screen_nav_test.exs`). And
`Trace.broadcast/3` folds over the table *in the calling process*, so its
cleanup is done by the time `dispatch/4` returns `:ok` (`event/trace_test.exs`).
These sleeps were guarding against nothing.

**Replaced with the real barrier (8).** A ready-message where the test was
waiting on another process to reach a known point (`trace_test.exs`,
`device_test.exs`); `Logger.flush/0` where it was waiting on handlers to drain
(`native_logger_test.exs` ×2, `theme_host_test.exs` ×2); a monitor where it was
waiting for an exit.

**Replaced with a bounded poll (3).** `device_test.exs` (×2) and
`native_component_examples_test.exs` wait for a GenServer to
process a `:DOWN` sent by a *monitor*, not by the test. Pairwise ordering does
not help here — the test never sent that message, so a `call` orders nothing
against it. `ProcessHelpers.eventually/2` polls with a deadline: it returns as
soon as the state is right rather than always paying the worst case, and it
fails with "condition still false after Nms" instead of letting the next
assertion report something confusing.

**Kept, deliberately (8).** Three in `render_stats_test.exs` are the subject
under test — it measures elapsed time, so time must actually elapse. Three are
the backoff *inside* a poll loop that has its own deadline (`eventually/2`
itself, `migration_test.exs`, `reset_transition_test.exs`). One is a `@doc`
example, quoting the bad pattern in order to name it. One remains a genuine
bet: `router_hot_path_test.exs:206` waits for a message the *screen* sent to
the router, and the test is neither party, so it has no ordering guarantee to
lean on. It is left as a sleep and recorded here rather than disguised.

One honest caveat about the `Logger.flush/0` swaps: with the barrier deleted
outright those tests still passed 8 times out of 8 on this machine, so the wait
is not demonstrably load-bearing here. `flush/0` is kept because it is the
correct primitive and costs nothing when there is nothing pending, whereas the
sleep it replaced was a guess that cost 300ms per run. That is a reason, not a
measurement, and is stated as such.

## Consequences

- `mix mob.flake` runs the suite repeatedly and reports which tests are
non-deterministic. Its green output says explicitly that a 1-in-17 flake
survives 20 green runs about 30% of the time, because "I ran it 20 times" is
the reasoning that let this persist.
- **The registry race is fixed by construction, not by demonstration.** It did
not reproduce here in 25 full-suite runs or 40 concentrated ones, so there is
no before-and-after to show. The mechanism is provable by reading the code
and it was observed once on this machine; the fix removes the ownership that
makes it possible. That is weaker evidence than a reproduction and is stated
as such.

- **Tightening `stop_pid/2` broke three tests, and only under a full run.**
Making the timeout raise meant replacing a blanket `:exit, _ -> :ok` with
enumerated clauses. The enumeration was wrong: a linked owner dying while
ExUnit tears the test down exits with `{{:shutdown, {:sys, :terminate, _}},
{GenServer, :stop, _}}`, which matched none of them. It passed every file run
on its own and failed 3 tests in one full run and 4 in the next. The fix is
to invert the logic — special-case only the timeout, treat every other exit
as "already gone" — because "did it stop" has one interesting answer and an
open-ended set of uninteresting ones. Enumerating the uninteresting set is a
bet on having seen every shutdown shape, which is the same class of mistake
as betting on a duration.
155 changes: 155 additions & 0 deletions lib/mix/tasks/mob.flake.ex
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,155 @@
defmodule Mix.Tasks.Mob.Flake do
@shortdoc "Run the suite repeatedly to surface flaky tests"

@moduledoc """
Run the test suite until it fails, or a set number of times, and report
which tests were not deterministic.

A flake does not announce itself. It fails once, on someone else's branch,
and the natural response is to re-run and move on — which is how a 1-in-17
failure survived long enough to corrupt a mutation-testing verdict and send
a bisect down the wrong path. This makes looking cheap and deliberate.

mix mob.flake # 20 runs, stop at the first failure
mix mob.flake --runs 50 # more attempts
mix mob.flake --until-failure # keep going until one fails
mix mob.flake --keep-going # run them all, report every failure
mix mob.flake test/mob/nav # narrow the target
mix mob.flake --seed 0 # fix the seed, so ordering is constant

## Reading the result

A test that fails under `--seed 0` on every run is not flaky, it is broken.
This looks for the other kind: tests that pass and fail with everything else
held still. Those are almost always a race — a `Process.sleep` standing in
for synchronisation, a check-then-act across a process boundary, or shared
global state (a named process, an ETS table) whose lifetime is tied to
whichever test happened to start it.

Narrowing helps more than volume. If a failure names one module, run that
module 200 times rather than the suite 20 more times.
"""

use Mix.Task

@switches [runs: :integer, until_failure: :boolean, keep_going: :boolean, seed: :integer]

@impl Mix.Task
def run(argv) do
{opts, paths} = OptionParser.parse!(argv, strict: @switches)

runs = Keyword.get(opts, :runs, 20)
until_failure? = Keyword.get(opts, :until_failure, false)
keep_going? = Keyword.get(opts, :keep_going, false)
limit = if until_failure?, do: :infinity, else: runs

Mix.shell().info([
:cyan,
"Running the suite #{describe(limit)}, ",
if(keep_going?, do: "reporting every failure.", else: "stopping at the first failure."),
:reset
])

loop(1, limit, keep_going?, opts, paths, [])
end

defp describe(:infinity), do: "until it fails"
defp describe(n), do: "#{n} time(s)"

defp loop(attempt, limit, keep_going?, opts, paths, failures) do
if limit != :infinity and attempt > limit do
report(attempt - 1, failures)
else
case run_once(opts, paths) do
:ok ->
IO.write(".")
loop(attempt + 1, limit, keep_going?, opts, paths, failures)

{:failed, output} ->
IO.write("F")
failures = [{attempt, output} | failures]

if keep_going? and limit != :infinity do
loop(attempt + 1, limit, keep_going?, opts, paths, failures)
else
report(attempt, failures)
end
end
end
end

defp run_once(opts, paths) do
args =
["test"] ++
paths ++
case Keyword.fetch(opts, :seed) do
{:ok, seed} -> ["--seed", to_string(seed)]
:error -> []
end

# Fresh OS process per run, deliberately: an in-process re-run would share
# the ETS tables and named processes that cause most of these failures, so
# it could not reproduce them.
{output, status} = System.cmd("mix", args, stderr_to_stdout: true, env: [{"MIX_ENV", "test"}])

if status == 0, do: :ok, else: {:failed, output}
end

defp report(runs, []) do
Mix.shell().info([:green, "\n\n#{runs} run(s), no failures.", :reset])

Mix.shell().info([
"\nThat is evidence, not proof. A 1-in-17 flake survives 20 green runs ",
"about 30% of the time — narrow the target and raise --runs before ",
"concluding a suspected flake is gone."
])
end

defp report(runs, failures) do
ordered = Enum.reverse(failures)

Mix.shell().error("\n\n#{length(ordered)} failure(s) in #{runs} run(s):\n")

for {attempt, output} <- ordered do
Mix.shell().error("── run #{attempt} " <> String.duplicate("─", 50))
Mix.shell().error(failing_tests(output))
end

Mix.shell().info([
"\nRe-run the named module alone, many times, before changing anything. ",
"A failure that only appears in the full suite is usually shared global ",
"state, not the test's own logic."
])

exit({:shutdown, 1})
end

# The whole log is noise; what matters is which tests failed and why.
#
# Split on failure headers rather than sliding a window over the lines. A
# window silently loses any failure near the end of the output — and because
# an earlier match makes the fallback unreachable, it loses it without saying
# so. For a tool that exists to surface rare failures, that is the worst
# possible bug, and it was in the first version of this function.
@header ~r/^\s+\d+\) (test|doctest|property) /

@doc false
@spec failing_tests(String.t()) :: [String.t()]
def failing_tests(output) do
output
|> String.split("\n")
|> Enum.reduce([], fn line, acc ->
cond do
Regex.match?(@header, line) -> [[line] | acc]
acc == [] -> acc
true -> [[line | hd(acc)] | tl(acc)]
end
end)
|> Enum.reverse()
|> Enum.map(fn block -> block |> Enum.reverse() |> Enum.take(8) |> Enum.join("\n") end)
|> case do
[] -> output |> String.split("\n") |> Enum.take(-15) |> Enum.join("\n")
blocks -> Enum.join(blocks, "\n\n")
end
end
end
10 changes: 2 additions & 8 deletions test/mob/component_server_test.exs
Original file line numberDiff line numberDiff line change
Expand Up@@ -75,10 +75,7 @@ defmodule Mob.ComponentServerTest do
# async test file (component_test.exs) may have already started it —
# start_supervised! would raise on {:already_started, _}, so tolerate
# that instead of racing to be first.
case start_supervised({Mob.ComponentRegistry, []}) do
{:ok, _pid} -> :ok
{:error, {:already_started, _pid}} -> :ok
end
Mob.Test.ProcessHelpers.ensure_component_registry()

{:ok, pid} =
Mob.ComponentServer.start(
Expand DownExpand Up@@ -253,10 +250,7 @@ defmodule Mob.ComponentServerTest do
end

setup do
case start_supervised({Mob.ComponentRegistry, []}) do
{:ok, _pid} -> :ok
{:error, {:already_started, _pid}} -> :ok
end
Mob.Test.ProcessHelpers.ensure_component_registry()

# Unlinked, fixed-name Agent (mirrors test/mob/renderer_test.exs's
# MockNIF) — reset rather than restarted, since a prior test in this
Expand Down
7 changes: 2 additions & 5 deletions test/mob/component_test.exs
Original file line numberDiff line numberDiff line change
Expand Up@@ -130,11 +130,8 @@ defmodule Mob.ComponentTest do
# racing to be first (MOB-98: this is the shared-name race that fix
# already covers on that file's side; this file needed the same
# tolerance).
reg =
case start_supervised({Mob.ComponentRegistry, []}) do
{:ok, pid} -> pid
{:error, {:already_started, pid}} -> pid
end
:ok = Mob.Test.ProcessHelpers.ensure_component_registry()
reg = Process.whereis(Mob.ComponentRegistry)

{:ok, reg: reg}
end
Expand Down
Loading
Loading