Skip to content

fix: slice 040 AC3 measures the watcher, not the machine - #113

Merged
HackTuah merged 3 commits into
mainfrom
fix/load-sensitive-tests
Oct 7, 2026
Merged

HackTuah merged 3 commits into
mainfrom
fix/load-sensitive-tests

Conversation

@HackTuah

Copy link
Copy Markdown
Member

Two tests were red on one machine and green on the other. The causes turned out to be unrelated, and neither was the product misbehaving.

Skills.RegistryTest AC3 — fixed

On CI there is no inotifywait, so the registry takes the fs_poll backend: a poll every second over mtimes at one-second resolution, whose worst case is about two seconds. AC3's bound is two seconds. No margin at all, and a loaded shared runner closes it. Measured with the backend forced:

fs_poll interval observed latency margin against 2000 ms
1000 ms (shipped) 1222, 1223 ms 777 ms
100 ms (suite) 339, 312, 338 ms ~1660 ms

The interval is now configurable and the suite sets 100 ms. The shipped default is unchanged: a desktop does not need a tenth-of-a-second poll, and the criterion is the same either way.

The suite also pins the backend. Which one the registry picks otherwise depends on the machine, so the test measured a different mechanism in each place. And on a box at its inotify instance ceiling the native backend obtains no watch and fails silently:

$ cat /proc/sys/fs/inotify/max_user_instances   ->  128
$ find /proc/*/fd -lname anon_inode:inotify | wc -l   ->  119

That is this machine, and it is why AC3 was red here. Not leaked by the suite: no stray inotifywait processes exist. The old assertion could only report it as

AC3: the edit was in the registry after  ms

because the poll window and the criterion were the same 2000 ms budget, so an exhausted loop and a late arrival were indistinguishable. They are separate now: the loop waits 15 s so a failure says which happened, and the criterion is asserted against the latency actually measured.

Verified where it was failing: three runs at 338, 338 and 312 ms, then a full gate.

mix gate
prod_check: PASS
3814 mods/funs, found no issues.
No vulnerabilities found.
trinity.names: OK over 674 tracked files
AC3: the edit was in the registry after 338 ms
Result: 951 passed (20 properties, 931 tests), 18 excluded
trinity.coverage: 042 80.31% vs 005 80.31%: OK
GATE_EXIT=0

Gateways.IdentitiesTest — diagnosed, not fixed

config/test.exs sets default_transaction_mode: :immediate on both test repos, which reads as though slice 005 had closed R26 for the suite. It has not.

# deps/ecto_sql/lib/ecto/adapters/sql/sandbox.ex:659
case conn_mod.handle_begin([mode: :transaction] ++ opts, conn_state) do

# deps/exqlite/lib/exqlite/connection.ex:298
mode = Keyword.get(options, :mode, state.default_transaction_mode)

The sandbox prepends an explicit :mode, so it wins over the configuration, and :transaction maps to a plain BEGIN TRANSACTION, which is DEFERRED. Every sandboxed test is a DEFERRED transaction. One that reads before it writes is on exactly R26's unguarded upgrade path, where SQLite returns SQLITE_BUSY without consulting the busy handler and no busy_timeout can help. Identities.admit/3 reads and then inserts, with no transaction of its own, and its first statement in the test is that call.

Recorded rather than asserted-and-forgotten: the comment in config/test.exs no longer implies the suite is covered, and test/trinity/repo/sandbox_transaction_mode_test.exs pins both dependency lines so the paragraph fails rather than rots if an upgrade moves them.

The test itself is unchanged. The mechanism needs a second concurrent writer, and I have not identified which process that is: the file is already async: false, DataCase puts it in shared mode so application processes use the owner's connection, and the failure does not reproduce here. I am not shipping a mitigation I cannot demonstrate.

If you want it closed, the cheapest honest option is to make that test's transaction a writer before its first read, since a fresh write consults the busy handler where an upgrade does not. Say so and I will verify the premise against the existing two-connection R26 harness first, rather than assuming it.

A third one, reported not touched

Trinity.SandboxTest "AC3 ... os.time and os.clock still work" failed once during this work:

right: {:error, {:timeout, 1000}}

A 1 s budget for a trivial Lua call. Same family, passed on the next run, outside what you asked for.

No new slice id, no ROADMAP row. Not merged.

The skills AC3 test was red on one machine and green on CI, and the reason was
different in each place. Neither was the watcher misbehaving.

On CI there is no inotifywait, so the registry takes the fs_poll backend: a poll
every second over mtimes at one-second resolution, whose worst case is about two
seconds. AC3's bound is two seconds. There was no margin at all, and a loaded
shared runner closed it. Measured here, with the backend forced:

  interval 1000 ms (shipped)  1222 ms, 1223 ms
  interval  100 ms (suite)     339 ms, 312 ms, 338 ms

The interval is now configurable and the suite sets 100 ms. The shipped default is
unchanged: a desktop does not need a tenth-of-a-second poll, and the criterion it
has to meet is the same either way.

The suite also pins the backend. Which one the registry picks otherwise depends on
the machine, so the test measured a different mechanism in each place. Worse, on a
box already at its inotify instance ceiling (128 here, 119 in use) the native
backend obtains no watch and fails silently: the test then fails for a reason that
has nothing to do with the product, and the old assertion could only report it as

  AC3: the edit was in the registry after  ms

because the poll window and the criterion were the same 2000 ms budget and an
exhausted loop was indistinguishable from a late arrival. They are separate now.
The loop waits 15 s so a failure says which of the two happened, and the criterion
is asserted against the latency actually measured.

Verified on the machine where it was failing: three runs, 338, 338 and 312 ms, and
a full gate at 951 passed.

R26 inside the sandbox, which is the other test

Gateways.IdentitiesTest fails on CI with Database busy on an insert, and
config/test.exs sets default_transaction_mode: :immediate on both test repos,
which reads as though slice 005 had covered the suite. It has not.
Ecto.Adapters.SQL.Sandbox.post_checkout/3 begins each test's transaction with
handle_begin([mode: :transaction] ++ opts, ...), and Exqlite.Connection resolves
the mode as Keyword.get(options, :mode, state.default_transaction_mode), so the
explicit option wins over the configuration and :transaction is a plain DEFERRED
BEGIN. Every sandboxed test is a DEFERRED transaction, and one that reads before it
writes is on R26's unguarded upgrade path, where no busy_timeout applies.
Identities.admit/3 reads and then inserts, with no transaction of its own.

That is diagnosis, not a fix, and it is recorded as such: the comment in
config/test.exs no longer implies the suite is covered, and
test/trinity/repo/sandbox_transaction_mode_test.exs asserts both dependency lines
so the paragraph fails rather than rots if an upgrade moves them. The identities
test is not changed, because the concurrent writer that completes the mechanism is
still unidentified and the failure does not reproduce here.

Signed-off-by: Ayla Croft <aylacroft@proton.me>
The six cases ran a child under MIX_ENV=dev, which meant each child compiled
the whole dev dependency tree from scratch. On a developer machine with a warm
_build that cost nothing. On CI it cost everything, in two different ways, and
only one of them was diagnosed at the time:

  the FIPS leg could not finish the compile at all, because fetching the
  tokenizers NIF needs a TLS handshake OTP cannot complete (erlang/otp#8470);

  the gate leg merely took too long, until a loaded runner pushed case 6 past
  its 180 s timeout and failed PR #113 while the other run of the same sha
  passed.

The dev compile was the defect. The FIPS leg was where it failed loudly, and
:needs_dev_compile treated that symptom by skipping the file on one leg. The tag
and its exclusion in test_helper.exs are both gone.

The child now runs MIX_ENV=test, reusing the tree the suite is already running
from: no compile, no network, on every leg.

Trinity.BootIsolation is what makes that safe, and it is why MIX_ENV=test was
rejected once. config/test.exs pins both the database and the data-directory
lock, and derives neither from XDG_DATA_HOME, so without it six children would
write into the suite's own chain and then refuse to boot on a lock the suite
holds. Measured before the helper existed: a child appended its boot receipt at
seq 360 on the live chain. The helper renames both repos' databases in whichever
shape the compiled adapter uses, creates the storage, runs the migrations the
child would otherwise skip (skip_migrations?/0 is Code.ensure_loaded?(Mix)),
drops the sandbox pool because a child is a real boot, and releases the pinned
lock path so XDG_DATA_HOME isolation works as the moduledoc always claimed.

The Postgres half is the part I previously declined to write because I could not
test it. It is now tested, against pgvector/pgvector:pg17 on 5433 with a separate
MIX_BUILD_ROOT=_build_pg tree:

  mix test test/trinity/regulated_boot_node_test.exs   6 passed, 9.9 s
  mix test --exclude sqlite                            931 passed, exit 0

and the per-case databases are dropped afterwards rather than leaked: after the
run, pg_database holds no trinity_boot% row and trinity_test is untouched.

On SQLite: 6 passed in 8.0 s, and mix gate 951 passed, exit 0.

Case 5 changed with the environment. It set TRINITY_MCP_AUTH_PROFILE and relied
on config/runtime.exs to map it, but that block is guarded by
config_env() != :test, so under the child's MIX_ENV=test the variable is read by
nothing. Left as it was, the case would have gone green on a node refusing for
the default reason rather than the one under test. It now sets :mcp_auth
directly and says why.

_build_pg is added to .gitignore: the adapter is chosen at compile time, so the
Postgres build cannot share a tree with the SQLite one.

Signed-off-by: Ayla Croft <aylacroft@proton.me>
…pens

Removing the FIPS exclusion let that leg run these cases for the first time, and
it immediately found a defect in the fixture rather than in the profile.

The key is receipts-<algorithm>.key (KeyCustody.key_path/2), and the algorithm is
:p384 whenever :crypto.info_fips() is :enabled, else :ed25519
(KeyCustody.select/0). The fixture created a directory named
receipts-ed25519.key, so on the FIPS leg it sabotaged a path the signer never
opens: the node generated a p384 key, booted, and case 6 failed on an assertion
that was correct. Case 1 passed there for the wrong reason, since it expects a
boot either way. Every candidate name is now taken.

Verified on both algorithms rather than reasoned about, by forcing
config :trinity, :receipts, algorithm: and reading the refusal:

  selected: {:ok, :ed25519}
  BOOT_REFUSED {:regulated_boot_refused, {:regulated_requires_receipts, {:key_file, :eisdir}}}
  selected: {:ok, :p384}
  BOOT_REFUSED {:regulated_boot_refused, {:regulated_requires_receipts, {:key_file, :eisdir}}}

Each candidate is a directory, which is not interchangeable with the simpler
sabotage of making keys_dir itself a regular file. A directory where the key
belongs gives File.read/1 {:error, :eisdir}, which KeyCustody returns as an error
tuple on the path the receipts supervisor is fail-open over. A keys_dir that is a
regular file instead makes File.mkdir_p!/1 raise %File.Error{reason: :enotdir},
and that takes the boot down under :default as well, so it cannot express "the
signer is down and a default node still starts". Measured while trying it:

  BOOT_REFUSED {:trinity, {{:shutdown, {:failed_to_start_child,
    Trinity.Receipts.Supervisor, {%File.Error{reason: :enotdir, ...

That is a narrower fail-open guarantee than the supervisor's own documentation
claims, it is a product observation rather than a test one, and it is filed as its
own finding rather than fixed here. receipts/supervisor.ex is untouched.

SQLite: 6 passed, and mix gate 951 passed, exit 0.
Postgres: 6 passed, 10.7 s, against pgvector:pg17 on 5433.
Signed-off-by: Ayla Croft <aylacroft@proton.me>
@HackTuah
HackTuah merged commit fa6b3e4 into main Oct 7, 2026
8 checks passed
@HackTuah
HackTuah deleted the fix/load-sensitive-tests branch October 7, 2026 20:40
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant