Compare commits
10 Commits
21d0c58835
...
c723e06c4f
| Author | SHA1 | Date |
|---|---|---|
|
|
c723e06c4f | |
|
|
629de67a69 | |
|
|
206e6a3af5 | |
|
|
1e84b2d95a | |
|
|
0ef5da8d8c | |
|
|
238e01a950 | |
|
|
33722bb6bf | |
|
|
a71c68613d | |
|
|
2fb8447309 | |
|
|
cf27b89e1e |
|
|
@ -0,0 +1,125 @@
|
||||||
|
# `RuntimeVars` env-var lift — design plan
|
||||||
|
|
||||||
|
Status: **draft, awaiting user edits**
|
||||||
|
|
||||||
|
## Goal
|
||||||
|
|
||||||
|
Consolidate the sprawl of pytest CLI flags + ad-hoc env vars +
|
||||||
|
hardcoded fixture defaults into a *single* env-var-encoded
|
||||||
|
runtime-vars envelope, with a typed in-memory representation
|
||||||
|
(`tractor.runtime._state.RuntimeVars`) as the sole source of
|
||||||
|
truth.
|
||||||
|
|
||||||
|
## Why now
|
||||||
|
|
||||||
|
- `--tpt-proto`, `--spawn-backend`, `--diag-on-hang`,
|
||||||
|
`--diag-capture-delay` and (soon) `TRACTOR_REG_ADDR` etc. are
|
||||||
|
proliferating. Each adds a parsing seam.
|
||||||
|
- `tests/devx/test_debugger.py` invokes example scripts as
|
||||||
|
separate subprocesses; they currently can't see the
|
||||||
|
fixture-allocated `reg_addr` at all (root cause of why
|
||||||
|
parametrizing devx scripts on `reg_addr` is on your TODO).
|
||||||
|
- Concurrent pytest sessions on the same host collide on
|
||||||
|
shared defaults (the `registry@1616` race we just fixed is
|
||||||
|
one symptom; per-session unique addr is the structural
|
||||||
|
fix).
|
||||||
|
- `tractor.runtime._state.RuntimeVars: Struct` is already
|
||||||
|
defined and **unused** — its docstring even says it
|
||||||
|
"should be utilized as possible for future calls."
|
||||||
|
|
||||||
|
## Design
|
||||||
|
|
||||||
|
### Module: `tractor/_testing/_rtvars.py`
|
||||||
|
|
||||||
|
Lifted from `modden.runtime.env`, ~50 LOC, no new deps.
|
||||||
|
|
||||||
|
```python
|
||||||
|
_TRACTOR_RT_VARS_OSENV: str = '_TRACTOR_RT_VARS'
|
||||||
|
|
||||||
|
def dump_rtvars(rtvars: RuntimeVars|dict) -> tuple[str, str]:
|
||||||
|
'''str-serialize via `str(dict)` — ast.literal_eval-able'''
|
||||||
|
|
||||||
|
def load_rtvars(env: dict) -> RuntimeVars:
|
||||||
|
'''ast.literal_eval the env-var value, hydrate to struct'''
|
||||||
|
|
||||||
|
def get_rtvars(proc: psutil.Process|None = None) -> RuntimeVars:
|
||||||
|
'''read the var from a target proc's env (or current)'''
|
||||||
|
|
||||||
|
def update_rtvars(
|
||||||
|
rtvars: RuntimeVars|dict|None = None,
|
||||||
|
update_osenv: bool|dict = True,
|
||||||
|
) -> tuple[str, str]:
|
||||||
|
'''mutate + re-encode + (optionally) write to os.environ'''
|
||||||
|
```
|
||||||
|
|
||||||
|
### Encoding choice: `str(dict)` + `ast.literal_eval`
|
||||||
|
|
||||||
|
Pros:
|
||||||
|
- stdlib only
|
||||||
|
- handles all the types tractor's tests need: `str`, `int`,
|
||||||
|
`float`, `bool`, `None`, `list`, `tuple`, `dict`
|
||||||
|
- human-readable in the env (greppable, inspectable via
|
||||||
|
`cat /proc/<pid>/environ | tr '\0' '\n'`)
|
||||||
|
|
||||||
|
Cons:
|
||||||
|
- non-stdlib types (msgspec Structs, `Path`, custom classes)
|
||||||
|
must be lowered first — fine for the test fixture set
|
||||||
|
- not stable across Python versions for esoteric repr cases
|
||||||
|
(we don't hit any)
|
||||||
|
|
||||||
|
Alternatives considered:
|
||||||
|
- **msgpack**: adds a dep + binary form is ungreppable
|
||||||
|
- **json**: doesn't preserve tuples (becomes lists), which is
|
||||||
|
a common type for `reg_addr`
|
||||||
|
- **toml/yaml**: heavier deps, no real benefit
|
||||||
|
|
||||||
|
### `RuntimeVars` becomes the single source of truth
|
||||||
|
|
||||||
|
The legacy `_runtime_vars: dict[str, Any]` global in
|
||||||
|
`runtime/_state.py` becomes a *cached view* of a
|
||||||
|
`RuntimeVars` singleton instance:
|
||||||
|
|
||||||
|
- `get_runtime_vars()` returns either the struct or a
|
||||||
|
`.to_dict()` view depending on caller's preference
|
||||||
|
- `set_runtime_vars(...)` validates against the struct schema
|
||||||
|
- spawn-time SpawnSpec sends the struct (already does
|
||||||
|
conceptually — just gets typed)
|
||||||
|
- `__setattr__` `breakpoint()` debug instrumentation gets
|
||||||
|
removed (unrelated cleanup, mentioned in conversation)
|
||||||
|
|
||||||
|
### Migration path
|
||||||
|
|
||||||
|
**Phase 0** *(prep)*: strip the stray `breakpoint()` from
|
||||||
|
`RuntimeVars.__setattr__`.
|
||||||
|
|
||||||
|
**Phase 1**: land `_rtvars.py` as a leaf module, used only by
|
||||||
|
test infra. Subprocess-spawned scripts in `tests/devx/`
|
||||||
|
read `_TRACTOR_RT_VARS` on startup → reconstruct
|
||||||
|
`RuntimeVars` → call `tractor.open_root_actor(**rtvars.as_kwargs())`.
|
||||||
|
Concurrent runs become deterministic-isolated because each
|
||||||
|
session writes a unique `_registry_addrs` into the env.
|
||||||
|
|
||||||
|
**Phase 2**: migrate runtime callers (`_state.get_runtime_vars`,
|
||||||
|
spawn `SpawnSpec`, `Actor.async_main`) to operate on the
|
||||||
|
struct directly, with the dict as a compat view that gets
|
||||||
|
deprecated.
|
||||||
|
|
||||||
|
**Phase 3** *(structural)*: per-session bindspace subdir
|
||||||
|
`/run/user/<uid>/tractor/<session_uuid>/` — encoded in the
|
||||||
|
rt-vars envelope, picked up by every subactor automatically.
|
||||||
|
Obsoletes the entire bindspace-leak warning class.
|
||||||
|
|
||||||
|
## Open design questions (user input wanted)
|
||||||
|
|
||||||
|
- (placeholder for your edits)
|
||||||
|
- (placeholder)
|
||||||
|
- (placeholder)
|
||||||
|
|
||||||
|
## Out-of-scope for this lift
|
||||||
|
|
||||||
|
- Anything in `modden.runtime.env` related to `Spawn`,
|
||||||
|
`WmCtl`, `Wks` — that's a workspace orchestration layer,
|
||||||
|
not an env-var helper. We only lift the four utility
|
||||||
|
functions + the var name constant.
|
||||||
|
- Switching to msgpack/json — explicitly chosen against
|
||||||
|
above.
|
||||||
|
|
@ -1,8 +1,16 @@
|
||||||
{
|
{
|
||||||
"permissions": {
|
"permissions": {
|
||||||
"allow": [
|
"allow": [
|
||||||
"Bash(date *)",
|
|
||||||
"Bash(cp .claude/*)",
|
"Bash(cp .claude/*)",
|
||||||
|
"Read(.claude/**)",
|
||||||
|
"Read(.claude/skills/run-tests/**)",
|
||||||
|
"Write(.claude/**/*commit_msg*)",
|
||||||
|
"Write(.claude/git_commit_msg_LATEST.md)",
|
||||||
|
"Skill(run-tests)",
|
||||||
|
"Skill(close-wkt)",
|
||||||
|
"Skill(open-wkt)",
|
||||||
|
"Skill(prompt-io)",
|
||||||
|
"Bash(date *)",
|
||||||
"Bash(git diff *)",
|
"Bash(git diff *)",
|
||||||
"Bash(git log *)",
|
"Bash(git log *)",
|
||||||
"Bash(git status)",
|
"Bash(git status)",
|
||||||
|
|
@ -23,14 +31,12 @@
|
||||||
"Bash(UV_PROJECT_ENVIRONMENT=py* uv sync:*)",
|
"Bash(UV_PROJECT_ENVIRONMENT=py* uv sync:*)",
|
||||||
"Bash(UV_PROJECT_ENVIRONMENT=py* uv run:*)",
|
"Bash(UV_PROJECT_ENVIRONMENT=py* uv run:*)",
|
||||||
"Bash(echo EXIT:$?:*)",
|
"Bash(echo EXIT:$?:*)",
|
||||||
"Write(.claude/*commit_msg*)",
|
"Bash(echo \"EXIT=$?\")",
|
||||||
"Write(.claude/git_commit_msg_LATEST.md)",
|
"Read(//tmp/**)"
|
||||||
"Skill(run-tests)",
|
|
||||||
"Skill(close-wkt)",
|
|
||||||
"Skill(open-wkt)",
|
|
||||||
"Skill(prompt-io)"
|
|
||||||
],
|
],
|
||||||
"deny": [],
|
"deny": [],
|
||||||
"ask": []
|
"ask": []
|
||||||
}
|
},
|
||||||
|
"prefersReducedMotion": false,
|
||||||
|
"outputStyle": "default"
|
||||||
}
|
}
|
||||||
|
|
|
||||||
|
|
@ -229,3 +229,69 @@ Unlike asyncio, trio allows checkpoints in
|
||||||
that does `await` can itself be cancelled (e.g.
|
that does `await` can itself be cancelled (e.g.
|
||||||
by nursery shutdown). Watch for cleanup code that
|
by nursery shutdown). Watch for cleanup code that
|
||||||
assumes it will run to completion.
|
assumes it will run to completion.
|
||||||
|
|
||||||
|
### Unbounded waits in cleanup paths
|
||||||
|
|
||||||
|
Any `await <event>.wait()` in a teardown path is
|
||||||
|
a latent deadlock unless the event's setter is
|
||||||
|
GUARANTEED to fire. If the setter depends on
|
||||||
|
external state (peer disconnects, child process
|
||||||
|
exit, subsequent task completion) that itself
|
||||||
|
depends on the current task's progress, you have
|
||||||
|
a mutual wait.
|
||||||
|
|
||||||
|
Rule: **bound every `await X.wait()` in cleanup
|
||||||
|
paths with `trio.move_on_after()`** unless you
|
||||||
|
can prove the setter is unconditionally reachable
|
||||||
|
from the state at the await site. Concrete recent
|
||||||
|
example: `ipc_server.wait_for_no_more_peers()` in
|
||||||
|
`async_main`'s finally (see
|
||||||
|
`ai/conc-anal/subint_forkserver_test_cancellation_leak_issue.md`
|
||||||
|
"probe iteration 3") — it was unbounded, and when
|
||||||
|
one peer-handler was stuck the wait-for-no-more-
|
||||||
|
peers event never fired, deadlocking the whole
|
||||||
|
actor-tree teardown cascade.
|
||||||
|
|
||||||
|
### The capture-pipe-fill hang pattern (grep this first)
|
||||||
|
|
||||||
|
When investigating any hang in the test suite
|
||||||
|
**especially under fork-based backends**, first
|
||||||
|
check whether the hang reproduces under `pytest
|
||||||
|
-s` (`--capture=no`). If `-s` makes it go away
|
||||||
|
you're not looking at a trio concurrency bug —
|
||||||
|
you're looking at a Linux pipe-buffer fill.
|
||||||
|
|
||||||
|
Mechanism: pytest replaces fds 1,2 with pipe
|
||||||
|
write-ends. Fork-child subactors inherit those
|
||||||
|
fds. High-volume error-log tracebacks (cancel
|
||||||
|
cascade spew) fill the 64KB pipe buffer. Child
|
||||||
|
`write()` blocks. Child can't exit. Parent's
|
||||||
|
`waitpid`/pidfd wait blocks. Deadlock cascades up
|
||||||
|
the tree.
|
||||||
|
|
||||||
|
Pre-existing guards in `tests/conftest.py` encode
|
||||||
|
this knowledge — grep these BEFORE blaming
|
||||||
|
concurrency:
|
||||||
|
|
||||||
|
```python
|
||||||
|
# tests/conftest.py:258
|
||||||
|
if loglevel in ('trace', 'debug'):
|
||||||
|
# XXX: too much logging will lock up the subproc (smh)
|
||||||
|
loglevel: str = 'info'
|
||||||
|
|
||||||
|
# tests/conftest.py:316
|
||||||
|
# can lock up on the `_io.BufferedReader` and hang..
|
||||||
|
stderr: str = proc.stderr.read().decode()
|
||||||
|
```
|
||||||
|
|
||||||
|
Full post-mortem +
|
||||||
|
`ai/conc-anal/subint_forkserver_test_cancellation_leak_issue.md`
|
||||||
|
for the canonical reproduction. Cost several
|
||||||
|
investigation sessions before catching it —
|
||||||
|
because the capture-pipe symptom was masked by
|
||||||
|
deeper cascade-deadlocks. Once the cascades were
|
||||||
|
fixed, the tree tore down enough to generate
|
||||||
|
pipe-filling log volume → capture-pipe finally
|
||||||
|
surfaced. Grep-note for future-self: **if a
|
||||||
|
multi-subproc tractor test hangs, `pytest -s`
|
||||||
|
first, conc-anal second.**
|
||||||
|
|
|
||||||
|
|
@ -249,22 +249,38 @@ ls -la /tmp/registry@*.sock 2>/dev/null \
|
||||||
surface PIDs + cmdlines to the user, offer cleanup:
|
surface PIDs + cmdlines to the user, offer cleanup:
|
||||||
|
|
||||||
```sh
|
```sh
|
||||||
# 1. kill test zombies scoped to THIS repo's python only
|
# 1. GRACEFUL FIRST (tractor is structured concurrent — it
|
||||||
# (don't pkill by bare pattern — that'd nuke legit
|
# catches SIGINT as an OS-cancel in `_trio_main` and
|
||||||
# long-running tractor apps like piker)
|
# cascades Portal.cancel_actor via IPC to every descendant.
|
||||||
pkill -f "$(pwd)/py[0-9]*/bin/python.*_actor_child_main|subint-forkserv"
|
# So always try SIGINT first with a bounded timeout; only
|
||||||
sleep 0.3
|
# escalate to SIGKILL if graceful cleanup doesn't complete).
|
||||||
pkill -9 -f "$(pwd)/py[0-9]*/bin/python.*_actor_child_main|subint-forkserv" 2>/dev/null
|
pkill -INT -f "$(pwd)/py[0-9]*/bin/python.*_actor_child_main|subint-forkserv"
|
||||||
|
|
||||||
# 2. if a test zombie holds :1616 specifically and doesn't
|
# 2. bounded wait for graceful teardown (usually sub-second).
|
||||||
|
# Loop until the processes exit, or timeout. Keep the
|
||||||
|
# bound tight — hung/abrupt-killed descendants usually
|
||||||
|
# hang forever, so don't wait more than a few seconds.
|
||||||
|
for i in $(seq 1 10); do
|
||||||
|
pgrep -f "$(pwd)/py[0-9]*/bin/python.*_actor_child_main|subint-forkserv" >/dev/null || break
|
||||||
|
sleep 0.3
|
||||||
|
done
|
||||||
|
|
||||||
|
# 3. ESCALATE TO SIGKILL only if graceful didn't finish.
|
||||||
|
if pgrep -f "$(pwd)/py[0-9]*/bin/python.*_actor_child_main|subint-forkserv" >/dev/null; then
|
||||||
|
echo 'graceful teardown timed out — escalating to SIGKILL'
|
||||||
|
pkill -9 -f "$(pwd)/py[0-9]*/bin/python.*_actor_child_main|subint-forkserv"
|
||||||
|
fi
|
||||||
|
|
||||||
|
# 4. if a test zombie holds :1616 specifically and doesn't
|
||||||
# match the above pattern, find its PID the hard way:
|
# match the above pattern, find its PID the hard way:
|
||||||
ss -tlnp 2>/dev/null | grep ':1616' # prints `users:(("<name>",pid=NNNN,...))`
|
ss -tlnp 2>/dev/null | grep ':1616' # prints `users:(("<name>",pid=NNNN,...))`
|
||||||
# then: kill <NNNN>
|
# then (same SIGINT-first ladder):
|
||||||
|
# kill -INT <NNNN>; sleep 1; kill -9 <NNNN> 2>/dev/null
|
||||||
|
|
||||||
# 3. remove stale UDS sockets
|
# 5. remove stale UDS sockets
|
||||||
rm -f /tmp/registry@*.sock
|
rm -f /tmp/registry@*.sock
|
||||||
|
|
||||||
# 4. re-verify
|
# 6. re-verify
|
||||||
ss -tlnp 2>/dev/null | grep ':1616' || echo 'TCP :1616 now free'
|
ss -tlnp 2>/dev/null | grep ':1616' || echo 'TCP :1616 now free'
|
||||||
```
|
```
|
||||||
|
|
||||||
|
|
@ -435,3 +451,73 @@ by your changes — note them and move on.
|
||||||
**Rule of thumb**: if a test fails with `TooSlowError`,
|
**Rule of thumb**: if a test fails with `TooSlowError`,
|
||||||
`trio.TooSlowError`, or `pexpect.TIMEOUT` and you didn't
|
`trio.TooSlowError`, or `pexpect.TIMEOUT` and you didn't
|
||||||
touch the relevant code path, it's flaky — skip it.
|
touch the relevant code path, it's flaky — skip it.
|
||||||
|
|
||||||
|
## 9. The pytest-capture hang pattern (CHECK THIS FIRST)
|
||||||
|
|
||||||
|
**Symptom:** a tractor test hangs indefinitely under
|
||||||
|
default `pytest` but passes instantly when you add
|
||||||
|
`-s` (`--capture=no`).
|
||||||
|
|
||||||
|
**Cause:** tractor subactors (especially under fork-
|
||||||
|
based backends) inherit pytest's stdout/stderr
|
||||||
|
capture pipes via fds 1,2. Under high-volume error
|
||||||
|
logging (e.g. multi-level cancel cascade, nested
|
||||||
|
`run_in_actor` failures, anything triggering
|
||||||
|
`RemoteActorError` + `ExceptionGroup` traceback
|
||||||
|
spew), the **64KB Linux pipe buffer fills** faster
|
||||||
|
than pytest drains it. Subactor writes block → can't
|
||||||
|
finish exit → parent's `waitpid`/pidfd wait blocks →
|
||||||
|
deadlock cascades up the tree.
|
||||||
|
|
||||||
|
**Pre-existing guards in the tractor harness** that
|
||||||
|
encode this same knowledge — grep these FIRST
|
||||||
|
before spelunking:
|
||||||
|
|
||||||
|
- `tests/conftest.py:258-260` (in the `daemon`
|
||||||
|
fixture): `# XXX: too much logging will lock up
|
||||||
|
the subproc (smh)` — downgrades `trace`/`debug`
|
||||||
|
loglevel to `info` to prevent the hang.
|
||||||
|
- `tests/conftest.py:316`: `# can lock up on the
|
||||||
|
_io.BufferedReader and hang..` — noted on the
|
||||||
|
`proc.stderr.read()` post-SIGINT.
|
||||||
|
|
||||||
|
**Debug recipe (in priority order):**
|
||||||
|
|
||||||
|
1. **Try `-s` first.** If the hang disappears with
|
||||||
|
`pytest -s`, you've confirmed it's capture-pipe
|
||||||
|
fill. Skip spelunking.
|
||||||
|
2. **Lower the loglevel.** Default `--ll=error` on
|
||||||
|
this project; if you've bumped it to `debug` /
|
||||||
|
`info`, try dropping back. Each log level
|
||||||
|
multiplies pipe-pressure under fault cascades.
|
||||||
|
3. **If you MUST use default capture + high log
|
||||||
|
volume**, redirect subactor stdout/stderr in the
|
||||||
|
child prelude (e.g.
|
||||||
|
`tractor.spawn._subint_forkserver._child_target`
|
||||||
|
post-`_close_inherited_fds`) to `/dev/null` or a
|
||||||
|
file.
|
||||||
|
|
||||||
|
**Signature tells you it's THIS bug (vs. a real
|
||||||
|
code hang):**
|
||||||
|
|
||||||
|
- Multi-actor test under fork-based backend
|
||||||
|
(`subint_forkserver`, eventually `trio_proc` too
|
||||||
|
under enough log volume).
|
||||||
|
- Multiple `RemoteActorError` / `ExceptionGroup`
|
||||||
|
tracebacks in the error path.
|
||||||
|
- Test passes with `-s` in the 5-10s range, hangs
|
||||||
|
past pytest-timeout (usually 30+ s) without `-s`.
|
||||||
|
- Subactor processes visible via `pgrep -af
|
||||||
|
subint-forkserv` or similar after the hang —
|
||||||
|
they're alive but blocked on `write()` to an
|
||||||
|
inherited stdout fd.
|
||||||
|
|
||||||
|
**Historical reference:** this deadlock cost a
|
||||||
|
multi-session investigation (4 genuine cascade
|
||||||
|
fixes landed along the way) that only surfaced the
|
||||||
|
capture-pipe issue AFTER the deeper fixes let the
|
||||||
|
tree actually tear down enough to produce pipe-
|
||||||
|
filling log volume. Full post-mortem in
|
||||||
|
`ai/conc-anal/subint_forkserver_test_cancellation_leak_issue.md`.
|
||||||
|
Lesson codified here so future-me grep-finds the
|
||||||
|
workaround before digging.
|
||||||
|
|
|
||||||
|
|
@ -148,9 +148,13 @@ jobs:
|
||||||
- name: Run tests
|
- name: Run tests
|
||||||
run: >
|
run: >
|
||||||
uv run
|
uv run
|
||||||
pytest tests/ -rsx
|
pytest
|
||||||
|
tests/
|
||||||
|
-rsx
|
||||||
--spawn-backend=${{ matrix.spawn_backend }}
|
--spawn-backend=${{ matrix.spawn_backend }}
|
||||||
--tpt-proto=${{ matrix.tpt_proto }}
|
--tpt-proto=${{ matrix.tpt_proto }}
|
||||||
|
--capture=fd
|
||||||
|
# ^XXX^ can't work with --spawn-method=main_thread_forkserver
|
||||||
|
|
||||||
# XXX legacy NOTE XXX
|
# XXX legacy NOTE XXX
|
||||||
#
|
#
|
||||||
|
|
|
||||||
|
|
@ -0,0 +1,281 @@
|
||||||
|
# `fork()` in a multi-threaded program — execution-side vs. memory-side of the same coin
|
||||||
|
|
||||||
|
A reference doc for readers who've encountered one of two
|
||||||
|
opposite-sounding framings of POSIX `fork()` semantics in a
|
||||||
|
multi-threaded program and are confused by the other.
|
||||||
|
|
||||||
|
This is a sibling to
|
||||||
|
`subint_fork_blocked_by_cpython_post_fork_issue.md` — that
|
||||||
|
doc covers a CPython-level refusal of fork-from-subint;
|
||||||
|
this one covers the more general POSIX layer, since
|
||||||
|
tractor's main-thread forkserver design rests on it.
|
||||||
|
|
||||||
|
## TL;DR
|
||||||
|
|
||||||
|
POSIX `fork()` only preserves the *calling* thread as a
|
||||||
|
runnable thread in the child — every other thread in the
|
||||||
|
parent simply never executes another instruction in the
|
||||||
|
child. trio's docs call this "leaked"; tractor's
|
||||||
|
`_main_thread_forkserver.py` docstring calls it "gone".
|
||||||
|
Both are correct: "gone" is the *execution* side (no
|
||||||
|
scheduler entry, no instructions retired), "leaked" is the
|
||||||
|
*memory* side (the dead threads' stacks and per-thread
|
||||||
|
heap structures still ride into the child's address space
|
||||||
|
as orphaned COW pages with no owner and no cleanup hook).
|
||||||
|
Same POSIX reality, two halves of the same coin.
|
||||||
|
|
||||||
|
## The two framings
|
||||||
|
|
||||||
|
[python-trio/trio#1614][trio-1614] (the canonical "trio +
|
||||||
|
fork" hazards thread) puts it this way:
|
||||||
|
|
||||||
|
> If you use `fork()` in a process with multiple threads,
|
||||||
|
> all the other thread stacks are just leaked: there's
|
||||||
|
> nothing else you can reasonably do with them.
|
||||||
|
|
||||||
|
`tractor.spawn._main_thread_forkserver`'s module docstring
|
||||||
|
(specifically the "What survives the fork? — POSIX
|
||||||
|
semantics" section) puts it this way:
|
||||||
|
|
||||||
|
> POSIX `fork()` only preserves the *calling* thread as a
|
||||||
|
> runnable thread in the child. Every other thread in the
|
||||||
|
> parent — trio's runner thread, any `to_thread` cache
|
||||||
|
> threads, anything else — never executes another
|
||||||
|
> instruction post-fork.
|
||||||
|
|
||||||
|
A reader bouncing between the two can be forgiven for
|
||||||
|
asking: well, *which* is it — leaked or gone?
|
||||||
|
|
||||||
|
The answer is "yes". They're describing the same POSIX
|
||||||
|
behavior from two different angles:
|
||||||
|
|
||||||
|
- trio is talking about the **bytes** the dead threads
|
||||||
|
leave behind — stacks, TLS slots, per-thread arena
|
||||||
|
metadata — and the fact that nothing in the child can
|
||||||
|
drive them forward, free them, or even safely walk
|
||||||
|
them. That's a memory leak in the strict sense: held
|
||||||
|
but unreachable.
|
||||||
|
- tractor is talking about the **execution** side
|
||||||
|
relevant to the forkserver design: which threads
|
||||||
|
retire instructions in the child? Exactly one — the
|
||||||
|
one that called `fork()`. Everything else, regardless
|
||||||
|
of the bytes left behind, is dead in a scheduler
|
||||||
|
sense.
|
||||||
|
|
||||||
|
Neither framing is wrong; they're just answering
|
||||||
|
different questions.
|
||||||
|
|
||||||
|
## POSIX `fork()` in a multi-threaded program — what actually happens
|
||||||
|
|
||||||
|
Per POSIX (and concretely on Linux glibc), the contract
|
||||||
|
of `fork()` in a multi-threaded process is:
|
||||||
|
|
||||||
|
1. The kernel creates a new process whose virtual
|
||||||
|
address space is a COW copy of the parent's. *All*
|
||||||
|
pages map across — code, heap, every thread's stack,
|
||||||
|
every malloc arena, every mmap region.
|
||||||
|
2. Of the parent's N threads, exactly **one** is
|
||||||
|
reified in the child as a runnable kernel task: the
|
||||||
|
thread that called `fork()`. The other N-1 threads
|
||||||
|
have *no* corresponding task in the child kernel. They
|
||||||
|
were never scheduled, never `clone()`d for the child,
|
||||||
|
never exist as runnable entities.
|
||||||
|
3. Their **memory artifacts** — pthread stacks, TLS,
|
||||||
|
`pthread_t` structures, glibc per-thread arena
|
||||||
|
bookkeeping — are still mapped in the child's address
|
||||||
|
space, because (1) duplicates *everything* page-wise.
|
||||||
|
They sit there as inert COW bytes.
|
||||||
|
4. The kernel does not clean those bytes up. There is no
|
||||||
|
"phantom-thread cleanup" pass post-fork. The kernel
|
||||||
|
doesn't know which mapped pages "belonged to" which
|
||||||
|
thread — at the kernel level mappings are
|
||||||
|
process-scoped, not thread-scoped.
|
||||||
|
5. The surviving thread (the caller of `fork()`) cannot
|
||||||
|
safely access those leaked bytes either. Any state
|
||||||
|
they encoded — held mutexes, in-flight syscalls,
|
||||||
|
half-updated invariants — is frozen at whatever
|
||||||
|
instant the parent's fork-syscall observed it. Some
|
||||||
|
of those mutexes may even still be locked from the
|
||||||
|
child's POV (the canonical "fork-in-multithreaded-
|
||||||
|
program-deadlocks" hazard; see `man pthread_atfork`).
|
||||||
|
|
||||||
|
So: from the kernel's PoV, the child has one thread.
|
||||||
|
From the address-space's PoV, the child has all the
|
||||||
|
parent's bytes — including the corpses of the N-1 dead
|
||||||
|
threads' stacks. Both true simultaneously.
|
||||||
|
|
||||||
|
## Why trio says "leaked"
|
||||||
|
|
||||||
|
trio's framing makes sense from the parent's
|
||||||
|
PoV, looking at *what those threads were doing*. In a
|
||||||
|
running `trio.run()` process you typically have:
|
||||||
|
|
||||||
|
- The trio runner thread itself — owns the `selectors`
|
||||||
|
epoll fd, the signal-wakeup-fd, the run-queue.
|
||||||
|
- Threadpool worker threads (`trio.to_thread`'s cache)
|
||||||
|
— blocked in `wait()` on the threadpool's work
|
||||||
|
condvar.
|
||||||
|
- Whatever other ad-hoc threads the application
|
||||||
|
started.
|
||||||
|
|
||||||
|
Each of those threads owns *real work-state*: epoll
|
||||||
|
registrations, file descriptors held in
|
||||||
|
soon-to-be-completed reads, half-released locks, posted
|
||||||
|
but unconsumed wakeups. After fork, that state is still
|
||||||
|
encoded in the child's memory. None of it is invalid in
|
||||||
|
a well-formed-bytes sense. It's just that:
|
||||||
|
|
||||||
|
- The thread that was driving it is gone.
|
||||||
|
- Nothing else in the child knows the layout well
|
||||||
|
enough to take over.
|
||||||
|
- Even if it did, the kernel objects backing the work
|
||||||
|
(epoll fd, signalfd) have separate post-fork
|
||||||
|
semantics that don't compose with userland trio
|
||||||
|
state.
|
||||||
|
|
||||||
|
So the bytes are *held* (they're in the child's
|
||||||
|
address space, they count against RSS, they survive
|
||||||
|
until something clobbers them), and they're
|
||||||
|
*unreachable* in any meaningful sense — no thread can
|
||||||
|
safely drive them forward. That is the textbook
|
||||||
|
definition of a leak.
|
||||||
|
|
||||||
|
trio's quote is reminding the user that `fork()` from a
|
||||||
|
multi-threaded process is a one-way memory hazard:
|
||||||
|
whatever those threads were doing, that work-state is
|
||||||
|
now garbage you happen to still be carrying.
|
||||||
|
|
||||||
|
## Why tractor says "gone"
|
||||||
|
|
||||||
|
tractor's `_main_thread_forkserver` framing is concerned
|
||||||
|
with a different question: *which thread executes in the
|
||||||
|
child, and is it safe?*
|
||||||
|
|
||||||
|
The forkserver design rests on POSIX's "calling thread
|
||||||
|
is the sole survivor" guarantee. We pick that calling
|
||||||
|
thread very deliberately: a dedicated worker that has
|
||||||
|
provably never entered trio. So the thread that *does*
|
||||||
|
run in the child is one whose locals, TLS, and stack
|
||||||
|
contain nothing trio-related. Trio's runner thread —
|
||||||
|
the one that owned the epoll fd and the run-queue — is
|
||||||
|
*gone* from the child in the execution sense. It will
|
||||||
|
never run another instruction. The fact that its stack
|
||||||
|
bytes still exist in the child's address space (the
|
||||||
|
"leaked" view) is irrelevant to the forkserver, because
|
||||||
|
nothing in the child reads or writes those pages.
|
||||||
|
|
||||||
|
So when the docstring says "Every other thread … is
|
||||||
|
gone the instant `fork()` returns in the child", it's
|
||||||
|
being precise about the surface that matters for the
|
||||||
|
backend: scheduler-level liveness. Nothing schedules
|
||||||
|
those threads ever again. Whether their bytes are
|
||||||
|
hanging around is a separate (and, for the design,
|
||||||
|
non-load-bearing) fact.
|
||||||
|
|
||||||
|
## Cross-table
|
||||||
|
|
||||||
|
The same tabular layout the `_main_thread_forkserver`
|
||||||
|
docstring uses, expanded with a fourth "what handles
|
||||||
|
it" column:
|
||||||
|
|
||||||
|
| thread | parent | child (executing) | child (memory) | what handles it |
|
||||||
|
|---------------------|-----------|-------------------|------------------------------|-----------------------------|
|
||||||
|
| forkserver worker | continues | sole survivor | live stack | runs the child's bootstrap |
|
||||||
|
| `trio.run()` thread | continues | not running | leaked stack (zombie bytes) | overwritten by child's fresh `trio.run()` |
|
||||||
|
| any other thread | continues | not running | leaked stack (zombie bytes) | overwritten / GC'd / clobbered by `exec()` if used |
|
||||||
|
|
||||||
|
The "child (executing)" column is the *execution* side
|
||||||
|
of the coin — what tractor cares about. The "child
|
||||||
|
(memory)" column is the *memory* side — what trio
|
||||||
|
cares about.
|
||||||
|
|
||||||
|
The "what handles it" column is the deliberate punchline
|
||||||
|
of the design: nothing has to handle the leaked bytes
|
||||||
|
*explicitly*. They get clobbered by ordinary forward
|
||||||
|
progress in the child:
|
||||||
|
|
||||||
|
- The fresh `trio.run()` the child boots up allocates
|
||||||
|
its own stack, scheduler, and run-queue, which over
|
||||||
|
time overlaps and overwrites the inherited zombie
|
||||||
|
pages.
|
||||||
|
- Python's GC walks live objects only; the dead-thread
|
||||||
|
Python frames aren't reachable from any
|
||||||
|
`PyThreadState`, so they get freed at the next
|
||||||
|
collection cycle.
|
||||||
|
- If the child eventually `exec()`s, the entire address
|
||||||
|
space is replaced and the leak vanishes.
|
||||||
|
|
||||||
|
## What this means for the forkserver design
|
||||||
|
|
||||||
|
The crucial point is that **the design doesn't and
|
||||||
|
*can't* prevent the leak**. There is no userland fix
|
||||||
|
for COW thread stacks. The kernel hands the child a
|
||||||
|
duplicated address space; that's what `fork()` *is*. No
|
||||||
|
amount of pre-fork hookery, `pthread_atfork()`
|
||||||
|
gymnastics, or post-fork cleanup can un-COW the dead
|
||||||
|
threads' pages without unmapping them, and unmapping
|
||||||
|
arbitrary regions of a duplicated address space is
|
||||||
|
neither portable nor safe.
|
||||||
|
|
||||||
|
What the design *does* ensure is the orthogonal
|
||||||
|
property: the survivor thread is one that doesn't need
|
||||||
|
any of that leaked state to function. Concretely:
|
||||||
|
|
||||||
|
- Survivor is the forkserver worker thread.
|
||||||
|
- That worker has provably never imported, called into,
|
||||||
|
or held any reference to `trio`. (Enforced by keeping
|
||||||
|
the worker's lifecycle entirely in
|
||||||
|
`_main_thread_forkserver.py` and never letting trio
|
||||||
|
task-state cross into it.)
|
||||||
|
- So the leaked pages — trio runner stack, threadpool
|
||||||
|
caches, etc. — are inert relative to the survivor.
|
||||||
|
No code path in the child references them.
|
||||||
|
- The child then boots its own fresh `trio.run()`,
|
||||||
|
which allocates new state in new pages. Over the
|
||||||
|
child's lifetime the COW'd zombie pages get
|
||||||
|
overwritten, GC'd, or (if the child eventually
|
||||||
|
`exec()`s) discarded wholesale.
|
||||||
|
|
||||||
|
The "leak" is real but inert. It costs RSS until
|
||||||
|
clobbered; it doesn't cost correctness. That's exactly
|
||||||
|
the property the forkserver pattern is built on, and
|
||||||
|
it's also why the design needs the "calling thread is
|
||||||
|
trio-free" precondition to be airtight: if the survivor
|
||||||
|
were a trio thread, it *would* try to drive the leaked
|
||||||
|
trio state, and the leak would no longer be inert.
|
||||||
|
|
||||||
|
## See also
|
||||||
|
|
||||||
|
- `tractor/spawn/_main_thread_forkserver.py` — module
|
||||||
|
docstring's "What survives the fork? — POSIX
|
||||||
|
semantics" section is the in-tree, code-adjacent
|
||||||
|
prose this doc expands on. The cross-table here is a
|
||||||
|
fourth-column expansion of the table there.
|
||||||
|
|
||||||
|
- [python-trio/trio#1614][trio-1614] — the trio issue
|
||||||
|
with the "leaked" framing, and the canonical thread
|
||||||
|
for trio + `fork()` hazards more broadly.
|
||||||
|
|
||||||
|
- [`subint_fork_blocked_by_cpython_post_fork_issue.md`](./subint_fork_blocked_by_cpython_post_fork_issue.md)
|
||||||
|
— sibling analysis covering CPython's *post-fork*
|
||||||
|
hooks (`PyOS_AfterFork_Child`,
|
||||||
|
`_PyInterpreterState_DeleteExceptMain`) and why
|
||||||
|
fork-from-non-main-subint is a CPython-level hard
|
||||||
|
refusal. Complementary axis: this doc is about POSIX
|
||||||
|
semantics; that doc is about the CPython runtime
|
||||||
|
layer that runs *after* POSIX `fork()` returns in
|
||||||
|
the child.
|
||||||
|
|
||||||
|
- `man pthread_atfork(3)` — canonical "fork in a
|
||||||
|
multithreaded process is dangerous" reference.
|
||||||
|
Especially the rationale section, which is the
|
||||||
|
closest thing to a normative statement of "the
|
||||||
|
surviving thread cannot safely use anything the dead
|
||||||
|
threads were touching."
|
||||||
|
|
||||||
|
- `man fork(2)` (Linux) — "Other than [the calling
|
||||||
|
thread], … no other threads are replicated …"
|
||||||
|
paragraph is the kernel-side statement of the
|
||||||
|
execution-side framing this doc opens with.
|
||||||
|
|
||||||
|
[trio-1614]: https://github.com/python-trio/trio/issues/1614
|
||||||
|
|
@ -0,0 +1,273 @@
|
||||||
|
# `test_register_duplicate_name` racy connect-failure on `daemon` fixture readiness
|
||||||
|
|
||||||
|
## Symptom
|
||||||
|
|
||||||
|
`tests/test_multi_program.py::test_register_duplicate_name`
|
||||||
|
fails intermittently under BOTH transports + ALL spawn
|
||||||
|
backends with connect-refused errors:
|
||||||
|
|
||||||
|
```
|
||||||
|
# under --tpt-proto=uds
|
||||||
|
FAILED tests/test_multi_program.py::test_register_duplicate_name
|
||||||
|
- ConnectionRefusedError: [Errno 111] Connection refused
|
||||||
|
( ^^^ this exc was collapsed from a group ^^^ )
|
||||||
|
|
||||||
|
# under --tpt-proto=tcp
|
||||||
|
FAILED tests/test_multi_program.py::test_register_duplicate_name
|
||||||
|
- OSError: all attempts to connect to 127.0.0.1:36003 failed
|
||||||
|
( ^^^ this exc was collapsed from a group ^^^ )
|
||||||
|
```
|
||||||
|
|
||||||
|
Distinct from the cancel-cascade `TooSlowError` flake
|
||||||
|
class — see
|
||||||
|
`cancel_cascade_too_slow_under_main_thread_forkserver_issue.md`.
|
||||||
|
This is a **connect-time race** before the daemon is
|
||||||
|
fully ready to `accept()`, not a teardown-cascade
|
||||||
|
slowness.
|
||||||
|
|
||||||
|
## Root cause: blind `time.sleep()` in `daemon` fixture
|
||||||
|
|
||||||
|
`tests/conftest.py::daemon` boots a sub-py-process via
|
||||||
|
`subprocess.Popen([python, '-c', 'tractor.run_daemon(...)'])`,
|
||||||
|
then **blindly sleeps** a fixed delay before yielding
|
||||||
|
`proc` to the test:
|
||||||
|
|
||||||
|
```python
|
||||||
|
# excerpt from tests/conftest.py::daemon
|
||||||
|
proc = subprocess.Popen([
|
||||||
|
sys.executable, '-c', code,
|
||||||
|
])
|
||||||
|
|
||||||
|
bg_daemon_spawn_delay: float = _PROC_SPAWN_WAIT # 0.6
|
||||||
|
if tpt_proto == 'uds':
|
||||||
|
bg_daemon_spawn_delay += 1.6
|
||||||
|
if _non_linux and ci_env:
|
||||||
|
bg_daemon_spawn_delay += 1
|
||||||
|
|
||||||
|
# XXX, allow time for the sub-py-proc to boot up.
|
||||||
|
# !TODO, see ping-polling ideas above!
|
||||||
|
time.sleep(bg_daemon_spawn_delay)
|
||||||
|
|
||||||
|
assert not proc.returncode
|
||||||
|
yield proc
|
||||||
|
```
|
||||||
|
|
||||||
|
Inherent fragility: the delay is "long enough on dev
|
||||||
|
boxes most of the time" but has no actual
|
||||||
|
synchronization with the daemon's `bind()` + `listen()`
|
||||||
|
completion. Under any of:
|
||||||
|
|
||||||
|
- Loaded box (CI parallelism, big rebuild in
|
||||||
|
background, low-cpu-freq)
|
||||||
|
- Cold first-run (`importlib` cache miss, JIT warmup)
|
||||||
|
- Higher-than-expected `tractor` import cost
|
||||||
|
- Filesystem latency (UDS sockfile create, slow
|
||||||
|
tmpfs)
|
||||||
|
|
||||||
|
...the sleep finishes BEFORE the daemon has bound its
|
||||||
|
listen socket → first test client call to
|
||||||
|
`tractor.find_actor()` / `wait_for_actor()` /
|
||||||
|
`open_nursery(registry_addrs=[reg_addr])`'s implicit
|
||||||
|
connect → `ConnectionRefusedError` (TCP) or
|
||||||
|
`FileNotFoundError`/`ConnectionRefusedError` (UDS).
|
||||||
|
|
||||||
|
## Reproducer
|
||||||
|
|
||||||
|
Easiest: run the suite under load.
|
||||||
|
|
||||||
|
```bash
|
||||||
|
# create CPU pressure on another core in parallel
|
||||||
|
stress-ng --cpu 2 --timeout 600s &
|
||||||
|
|
||||||
|
./py313/bin/python -m pytest \
|
||||||
|
tests/test_multi_program.py::test_register_duplicate_name \
|
||||||
|
--spawn-backend=main_thread_forkserver \
|
||||||
|
--tpt-proto=tcp -v
|
||||||
|
```
|
||||||
|
|
||||||
|
Reproduces ~30-50% of the time on a dev laptop. On a
|
||||||
|
quiet idle box, may need 5-10 runs to hit.
|
||||||
|
|
||||||
|
## Why the existing `_PROC_SPAWN_WAIT` tuning is
|
||||||
|
inadequate
|
||||||
|
|
||||||
|
Recent `bg_daemon_spawn_delay` rename
|
||||||
|
(de-monotonic-grow fix) just-shipped removed the
|
||||||
|
*accumulation* bug where each invocation made the
|
||||||
|
NEXT test's wait longer too. Net effect: every
|
||||||
|
invocation now uses the SAME `0.6 + 1.6` (UDS) or
|
||||||
|
`0.6` (TCP) sleep, no growth. Good — but does
|
||||||
|
NOTHING for the underlying race. Each individual
|
||||||
|
test still relies on a blind sleep that may or may
|
||||||
|
not be sufficient.
|
||||||
|
|
||||||
|
Bumping the constant higher pushes flake rate down
|
||||||
|
but never to zero AND adds dead time to every
|
||||||
|
non-flaking run. Not a fix, just a knob.
|
||||||
|
|
||||||
|
## Side effects
|
||||||
|
|
||||||
|
- **Inter-test cascade**: a single failure can cascade
|
||||||
|
via leaked subprocesses (the `daemon` fixture's
|
||||||
|
cleanup may not fully tear down a daemon that never
|
||||||
|
reached "ready"). The `_reap_orphaned_subactors`
|
||||||
|
session-end + `_track_orphaned_uds_per_test`
|
||||||
|
per-test fixtures handle most of this now, but the
|
||||||
|
affected test itself still fails.
|
||||||
|
- **Worsens under fork-spawn backends**: the daemon
|
||||||
|
has more init work
|
||||||
|
(`_main_thread_forkserver`-coordinator-thread
|
||||||
|
startup, etc.) so the sleep has to cover MORE.
|
||||||
|
|
||||||
|
## Fix design — replace blind sleep with active poll
|
||||||
|
|
||||||
|
The right primitive is **poll the daemon's bind
|
||||||
|
address until it accepts a connection or we time
|
||||||
|
out**, with the timeout being a hard ceiling rather
|
||||||
|
than a baseline. Two implementation paths:
|
||||||
|
|
||||||
|
### Path A — TCP/UDS connect-poll loop
|
||||||
|
|
||||||
|
Try `socket.connect(reg_addr)` in a tight loop with
|
||||||
|
short backoff (~50ms), succeed on the first non-error
|
||||||
|
return, fail-loud on a hard cap (e.g. 10s). Same
|
||||||
|
primitive works for both transports because both use
|
||||||
|
`socket.connect()` semantics.
|
||||||
|
|
||||||
|
Rough shape:
|
||||||
|
|
||||||
|
```python
|
||||||
|
def _wait_for_daemon_ready(
|
||||||
|
reg_addr,
|
||||||
|
tpt_proto: str,
|
||||||
|
timeout: float = 10.0,
|
||||||
|
poll_interval: float = 0.05,
|
||||||
|
) -> None:
|
||||||
|
deadline = time.monotonic() + timeout
|
||||||
|
while True:
|
||||||
|
if tpt_proto == 'tcp':
|
||||||
|
sock = socket.socket(socket.AF_INET)
|
||||||
|
target = reg_addr # (host, port)
|
||||||
|
else: # uds
|
||||||
|
sock = socket.socket(socket.AF_UNIX)
|
||||||
|
target = os.path.join(*reg_addr)
|
||||||
|
try:
|
||||||
|
sock.settimeout(poll_interval)
|
||||||
|
sock.connect(target)
|
||||||
|
except (
|
||||||
|
ConnectionRefusedError,
|
||||||
|
FileNotFoundError,
|
||||||
|
socket.timeout,
|
||||||
|
) as exc:
|
||||||
|
if time.monotonic() >= deadline:
|
||||||
|
raise TimeoutError(
|
||||||
|
f'Daemon never accepted on {target!r} '
|
||||||
|
f'within {timeout}s'
|
||||||
|
) from exc
|
||||||
|
time.sleep(poll_interval)
|
||||||
|
else:
|
||||||
|
sock.close()
|
||||||
|
return
|
||||||
|
```
|
||||||
|
|
||||||
|
Pros: trivial primitive, no tractor-runtime
|
||||||
|
dependency, works pre-yield in the fixture body,
|
||||||
|
fail-fast on truly-broken daemon.
|
||||||
|
Cons: doesn't actually do an IPC handshake, just
|
||||||
|
proves listen-side is up. A daemon that bound but
|
||||||
|
hasn't initialized its registrar table yet would
|
||||||
|
still race.
|
||||||
|
|
||||||
|
### Path B — `tractor.find_actor()` poll
|
||||||
|
|
||||||
|
Use the actual discovery API the test would call:
|
||||||
|
|
||||||
|
```python
|
||||||
|
async def _wait_for_daemon_ready_via_discovery(
|
||||||
|
reg_addr,
|
||||||
|
timeout: float = 10.0,
|
||||||
|
poll_interval: float = 0.05,
|
||||||
|
):
|
||||||
|
deadline = trio.current_time() + timeout
|
||||||
|
async with tractor.open_root_actor(
|
||||||
|
registry_addrs=[reg_addr],
|
||||||
|
# ephemeral root just for the probe
|
||||||
|
):
|
||||||
|
while True:
|
||||||
|
try:
|
||||||
|
async with tractor.find_actor(
|
||||||
|
'registrar', # daemon's own name
|
||||||
|
registry_addrs=[reg_addr],
|
||||||
|
) as portal:
|
||||||
|
if portal is not None:
|
||||||
|
return
|
||||||
|
except Exception:
|
||||||
|
pass
|
||||||
|
if trio.current_time() >= deadline:
|
||||||
|
raise TimeoutError(...)
|
||||||
|
await trio.sleep(poll_interval)
|
||||||
|
```
|
||||||
|
|
||||||
|
Pros: actually proves the discovery path works,
|
||||||
|
handles the "bound but not ready" case naturally.
|
||||||
|
Cons: requires booting an ephemeral root actor JUST
|
||||||
|
for the probe (overhead), more code, and runs in trio
|
||||||
|
which complicates the sync-fixture context. Need a
|
||||||
|
`trio.run()` wrapper.
|
||||||
|
|
||||||
|
### Recommended: Path A with optional handshake check
|
||||||
|
|
||||||
|
Path A is much simpler + handles 95% of the bug
|
||||||
|
class. If "bound-but-not-ready" turns out to still
|
||||||
|
race (it shouldn't — `tractor.run_daemon` doesn't
|
||||||
|
return from `bind()` until the registrar is
|
||||||
|
fully populated), escalate to Path B as a focused
|
||||||
|
follow-up.
|
||||||
|
|
||||||
|
## Workarounds (until fix lands)
|
||||||
|
|
||||||
|
1. **Bump `_PROC_SPAWN_WAIT`** higher (current: 0.6).
|
||||||
|
2.0–3.0 hides most flakes at the cost of adding
|
||||||
|
dead time to every test. Not a fix but reduces
|
||||||
|
blast radius while the proper poll lands.
|
||||||
|
2. **`pytest-rerunfailures`** with `reruns=1` on the
|
||||||
|
`daemon` fixture's tests specifically. Hides the
|
||||||
|
flake but doesn't address it.
|
||||||
|
3. **Mark known-affected tests as `xfail(strict=False)`**
|
||||||
|
under `--ci`. Lets CI go green at the cost of
|
||||||
|
silently hiding regressions.
|
||||||
|
|
||||||
|
(Recommend skipping all three — implement the active
|
||||||
|
poll instead.)
|
||||||
|
|
||||||
|
## Investigation next steps
|
||||||
|
|
||||||
|
1. Implement Path A as a `_wait_for_daemon_ready()`
|
||||||
|
helper in `tests/conftest.py`. Replace the
|
||||||
|
`time.sleep(bg_daemon_spawn_delay)` call with it.
|
||||||
|
2. Drop the `_PROC_SPAWN_WAIT` constant entirely
|
||||||
|
(active poll obsoletes blind sleep).
|
||||||
|
3. Run the suite 5-10 times to validate flake rate
|
||||||
|
drops to 0.
|
||||||
|
4. If flakes persist, profile whether the daemon
|
||||||
|
process exits with non-zero before the poll's
|
||||||
|
deadline hits — that'd be a different bug
|
||||||
|
(daemon startup crash) that the blind sleep was
|
||||||
|
masking.
|
||||||
|
5. Cross-check `tests/test_multi_program.py::test_*`
|
||||||
|
— multiple tests use the `daemon` fixture; all
|
||||||
|
should benefit from the same poll primitive.
|
||||||
|
|
||||||
|
## Related
|
||||||
|
|
||||||
|
- `tests/conftest.py::daemon` — the fixture under
|
||||||
|
fix
|
||||||
|
- `tests/conftest.py::_PROC_SPAWN_WAIT` — the
|
||||||
|
constant to drop
|
||||||
|
- `cancel_cascade_too_slow_under_main_thread_forkserver_issue.md`
|
||||||
|
— distinct flake class (cancel-cascade
|
||||||
|
`TooSlowError` at teardown, not connect-time race)
|
||||||
|
- `trio_wakeup_socketpair_busy_loop_under_fork_issue.md`
|
||||||
|
— different bug entirely; this race was masked
|
||||||
|
pre-WakeupSocketpair-patch by the busy-loop
|
||||||
|
hangs.
|
||||||
|
|
@ -0,0 +1,159 @@
|
||||||
|
# Logging-spec leaf-module granularity — "Route B" (decouple
|
||||||
|
# logger-*identity* from console-*display*)
|
||||||
|
|
||||||
|
Follow-up notes recording the breaking-changes / costs of the
|
||||||
|
deeper fix that would give the `tractor.log` logging-spec (see
|
||||||
|
`LogSpec`/`apply_logspec()`) true **per-leaf-MODULE** level
|
||||||
|
control — deliberately *not* taken (for now) in favour of the
|
||||||
|
smaller sub-PACKAGE fix already landed.
|
||||||
|
|
||||||
|
## Status / what already shipped
|
||||||
|
|
||||||
|
The cheap, contained fix is **done**: `get_logger()`'s "strip
|
||||||
|
#2" (`log.py`, the `pkg_path = subpkg_path` collapse) no longer
|
||||||
|
eats a real sub-package component. It now strips the trailing
|
||||||
|
token *only* when it duplicates the caller's leaf-*module*
|
||||||
|
filename (which the header already shows via `{filename}`).
|
||||||
|
|
||||||
|
Result:
|
||||||
|
|
||||||
|
- `devx.debug` resolves to `tractor.devx.debug`, **distinct**
|
||||||
|
from a bare `devx` -> `tractor.devx` (its parent). So the
|
||||||
|
logging-spec can dial sub-package levels at any nesting depth
|
||||||
|
(`devx.debug:runtime` ≠ `devx:cancel`).
|
||||||
|
- The `get_logger(__name__)` cosmetic ("don't repeat the leaf
|
||||||
|
module in `{name}` since `{filename}` shows it") is preserved.
|
||||||
|
|
||||||
|
What is **still NOT addressable** after that fix:
|
||||||
|
|
||||||
|
- **Per-leaf-MODULE** levels. Every module in a (sub-)pkg shares
|
||||||
|
that pkg's logger, because `get_logger()` drops the leaf
|
||||||
|
module-name from the logger key by design.
|
||||||
|
- **Top-level lib modules** (eg. `tractor.to_asyncio`,
|
||||||
|
`__package__ == 'tractor'`) emit on the *root* `tractor`
|
||||||
|
logger, so a `to_asyncio:<lvl>` spec entry hits a phantom
|
||||||
|
child -> no-op.
|
||||||
|
|
||||||
|
## What "Route B" is
|
||||||
|
|
||||||
|
Make the logger's *identity* the **full dotted module path**
|
||||||
|
(incl. the leaf module + top-level modules), eg.
|
||||||
|
`tractor.devx.debug._tty_lock` and `tractor.to_asyncio`, and
|
||||||
|
move the cosmetic leaf-trim out of logger-naming and into the
|
||||||
|
**formatter's `{name}` rendering**.
|
||||||
|
|
||||||
|
Net effect:
|
||||||
|
|
||||||
|
- Real per-module `Logger` nodes exist in the hierarchy ->
|
||||||
|
the spec can target ANY module; stdlib level-inheritance and
|
||||||
|
propagation "just work" top-down.
|
||||||
|
- Console headers stay clean because the formatter computes a
|
||||||
|
trimmed display string (drop the trailing token that equals
|
||||||
|
`{filename}`'s stem) instead of the logger doing it.
|
||||||
|
|
||||||
|
## Why it's "broad" — breaking changes / costs
|
||||||
|
|
||||||
|
The logger *name* is currently load-bearing well beyond
|
||||||
|
display; changing it ripples:
|
||||||
|
|
||||||
|
1. **Every logger name changes.**
|
||||||
|
Today (post sub-pkg fix) names collapse to the sub-package;
|
||||||
|
Route B = full module path. This touches:
|
||||||
|
- handler attachment points + the `getChild()` hierarchy,
|
||||||
|
- any `logging.getLogger('tractor.X')` string lookups,
|
||||||
|
- any name-based filtering,
|
||||||
|
- the dedup / `_strict_debug` warning logic *inside*
|
||||||
|
`get_logger()` itself — the `pkg_name in name`,
|
||||||
|
`leaf_mod in pkg_path`, "duplicate pkg-name" branches all
|
||||||
|
key off the *name shape* and would need re-derivation.
|
||||||
|
|
||||||
|
2. **Formatter rewrite.**
|
||||||
|
`LOG_FORMAT` uses `{name}` == `record.name` (the full logger
|
||||||
|
name). To keep headers clean we must compute a *display*
|
||||||
|
name and inject it as a record attr (eg. `record.pkg_ns`)
|
||||||
|
via a `logging.Filter` or a `colorlog.ColoredFormatter`
|
||||||
|
subclass overriding `.format()`, then point `LOG_FORMAT` at
|
||||||
|
that field. The `{filename}` vs `{name}` de-dup intent has
|
||||||
|
to be re-implemented per-record rather than per-logger.
|
||||||
|
|
||||||
|
3. **Propagation / double-emit surface grows.**
|
||||||
|
Full-depth loggers mean more intermediate nodes
|
||||||
|
(`...debug._tty_lock` -> `.debug` -> `.devx` -> `tractor`).
|
||||||
|
If more than one level carries a handler (spec sub-handlers
|
||||||
|
+ a root console), records double-emit. The
|
||||||
|
`propagate=False` trick we already use for filter-targeted
|
||||||
|
sub-loggers (`apply_logspec()`) must be applied carefully
|
||||||
|
across a deeper tree — more levels == more places to leak a
|
||||||
|
dup.
|
||||||
|
|
||||||
|
4. **Level-inheritance semantics shift.**
|
||||||
|
Today setting a level on `tractor.devx` gates *all* devx
|
||||||
|
emits (they share that logger). Post-Route-B,
|
||||||
|
`tractor.devx.debug._tty_lock` is its own `NOTSET` logger
|
||||||
|
that *inherits* the effective level from ancestors —
|
||||||
|
functionally similar via inheritance, BUT any code that does
|
||||||
|
`log.setLevel(...)` / reads `log.level` on a (previously
|
||||||
|
collapsed) logger now only affects that exact node. All
|
||||||
|
`setLevel`/`.level =` call sites need an audit (eg.
|
||||||
|
`get_logger()`'s own `log.level = rlog.level` line).
|
||||||
|
|
||||||
|
5. **Downstream contract churn.**
|
||||||
|
`modden` / `piker` call `get_logger()` / `get_console_log()`
|
||||||
|
and may depend on current names — including
|
||||||
|
`modden.runtime.daemon.setup_tractor_logging()` which
|
||||||
|
asserts `'tractor' not in name` on spec parts. The header
|
||||||
|
`{name}` field is user-visible in everyone's logs + CI
|
||||||
|
output. Changing the canonical names is a public-ish
|
||||||
|
behavior change -> needs a version note + downstream
|
||||||
|
coordination (or a formatter trim that keeps the *displayed*
|
||||||
|
string byte-identical to today).
|
||||||
|
|
||||||
|
6. **`get_logger()` refactor risk.**
|
||||||
|
The fn tangles two concerns: compute logger *identity* and
|
||||||
|
compute the *display* string. Route B forces splitting them
|
||||||
|
inside a ~300-line fn with multiple `_strict_debug`
|
||||||
|
branches, dup-warnings, and the `name=__name__` convenience.
|
||||||
|
High chance of subtle regressions without an exhaustive
|
||||||
|
name-derivation test matrix.
|
||||||
|
|
||||||
|
## Migration / test plan (if pursued)
|
||||||
|
|
||||||
|
- Extract a pure helper
|
||||||
|
`_mk_logger_name(pkg_name, mod_name, mod_pkg) -> (logger_name,
|
||||||
|
display_name)` and cover it with an exhaustive unit matrix:
|
||||||
|
auto vs explicit vs `__name__`; package-`__init__` vs leaf
|
||||||
|
module; nested vs flat; `pkg_name in name` vs not; top-level
|
||||||
|
module (`__package__ == pkg_name`).
|
||||||
|
- Switch `get_logger()` to use it for *identity*; switch the
|
||||||
|
formatter to use `display_name` (via a record attr).
|
||||||
|
- Re-run the full suite + golden-diff a sample of rendered log
|
||||||
|
headers to confirm zero cosmetic churn.
|
||||||
|
- Coordinate the name change with `modden`/`piker`; bump +
|
||||||
|
CHANGES note.
|
||||||
|
|
||||||
|
## Cheaper alternative — "Route A" (record-filter)
|
||||||
|
|
||||||
|
If per-leaf control is wanted *before* committing to Route B:
|
||||||
|
keep names collapsed, add a `logging.Filter` on the configured
|
||||||
|
handler keyed on `record.module` / `record.pathname` that maps
|
||||||
|
each record's source module -> its spec level. Set the base
|
||||||
|
logger to the *minimum* level in the spec (so records aren't
|
||||||
|
pre-dropped by the logger), and let the filter discriminate
|
||||||
|
up/down within that floor.
|
||||||
|
|
||||||
|
- Pros: no name churn, no formatter change, fully contained
|
||||||
|
next to `apply_logspec()`.
|
||||||
|
- Cons: a filter can only discriminate *within* what the logger
|
||||||
|
admits -> base must be permissive, so `at_least_level()`
|
||||||
|
expensive-work guards over-admit; matching dotted spec names
|
||||||
|
to a `pathname` is fiddly; doesn't clean up the hierarchy
|
||||||
|
itself.
|
||||||
|
|
||||||
|
## Recommendation
|
||||||
|
|
||||||
|
- Defer Route B unless true per-module loggers are wanted as a
|
||||||
|
first-class feature.
|
||||||
|
- If per-leaf control is needed soon, prefer **Route A**
|
||||||
|
(filter) — lower risk.
|
||||||
|
- The shipped sub-PACKAGE fix already covers the common ask
|
||||||
|
(`devx.debug` vs `devx`).
|
||||||
|
|
@ -77,13 +77,19 @@ testing = [
|
||||||
# test suite
|
# test suite
|
||||||
# TODO: maybe some of these layout choices?
|
# TODO: maybe some of these layout choices?
|
||||||
# https://docs.pytest.org/en/8.0.x/explanation/goodpractices.html#choosing-a-test-layout-import-rules
|
# https://docs.pytest.org/en/8.0.x/explanation/goodpractices.html#choosing-a-test-layout-import-rules
|
||||||
"pytest>=8.3.5",
|
# bumped 8.3.5 → 9.0 per upstream security advisory + our
|
||||||
|
# local-only reliance on the post-9.0 capture-machinery shape
|
||||||
|
# (the `sys.__stderr__`-bypass print in
|
||||||
|
# `tractor._testing.trace._do_capture_snapshot` works on 8.x
|
||||||
|
# too, but standardizing on 9.x here ensures `--show-capture`
|
||||||
|
# interactions stay predictable across dev installs).
|
||||||
|
"pytest>=9.0",
|
||||||
"pexpect>=4.9.0,<5",
|
"pexpect>=4.9.0,<5",
|
||||||
]
|
]
|
||||||
repl = [
|
repl = [
|
||||||
"pyperclip>=1.9.0",
|
"pyperclip>=1.9.0",
|
||||||
"prompt-toolkit>=3.0.50",
|
"prompt-toolkit>=3.0.50",
|
||||||
"xonsh>=0.22.8",
|
"xonsh>=0.23.0",
|
||||||
"psutil>=7.0.0",
|
"psutil>=7.0.0",
|
||||||
]
|
]
|
||||||
lint = [
|
lint = [
|
||||||
|
|
@ -124,7 +130,7 @@ sync_pause = {requires-python = ">=3.13, <3.14"}
|
||||||
# xonsh = { git = 'https://github.com/anki-code/xonsh.git', branch = 'prompt_next_suggestion' }
|
# xonsh = { git = 'https://github.com/anki-code/xonsh.git', branch = 'prompt_next_suggestion' }
|
||||||
# ^ https://github.com/xonsh/xonsh/pull/6048
|
# ^ https://github.com/xonsh/xonsh/pull/6048
|
||||||
# xonsh = { git = 'https://github.com/xonsh/xonsh.git', branch = 'main' }
|
# xonsh = { git = 'https://github.com/xonsh/xonsh.git', branch = 'main' }
|
||||||
xonsh = { path = "../xonsh", editable = true }
|
# xonsh = { path = "../xonsh", editable = true }
|
||||||
|
|
||||||
# [tool.uv.sources.pdbp]
|
# [tool.uv.sources.pdbp]
|
||||||
# XXX, in case we need to tmp patch again.
|
# XXX, in case we need to tmp patch again.
|
||||||
|
|
@ -193,7 +199,35 @@ all_bullets = true
|
||||||
|
|
||||||
[tool.pytest.ini_options]
|
[tool.pytest.ini_options]
|
||||||
minversion = '6.0'
|
minversion = '6.0'
|
||||||
timeout = 200 # per-test hard limit
|
# NOTE: `pytest-timeout`'s global per-test cap is intentionally
|
||||||
|
# NOT set — both of its enforcement methods break trio's
|
||||||
|
# runtime under our fork-based spawn backends:
|
||||||
|
#
|
||||||
|
# - `method='signal'` (the default; SIGALRM) raises `Failed`
|
||||||
|
# synchronously from the signal handler in trio's main
|
||||||
|
# thread, which leaves `GLOBAL_RUN_CONTEXT` half-installed
|
||||||
|
# ("Trio guest run got abandoned"). EVERY subsequent
|
||||||
|
# `trio.run()` in the same pytest session then bails with
|
||||||
|
# `RuntimeError: Attempted to call run() from inside a
|
||||||
|
# run()` — full-session poison: a single 200s hang
|
||||||
|
# cascades into 30+ false-positive failures across
|
||||||
|
# downstream test files.
|
||||||
|
#
|
||||||
|
# - `method='thread'` calls `_thread.interrupt_main()` which
|
||||||
|
# can let the resulting `KeyboardInterrupt` escape trio's
|
||||||
|
# `KIManager` under fork-cascade teardown races, killing
|
||||||
|
# the whole pytest session.
|
||||||
|
#
|
||||||
|
# For tests that legitimately need a wall-clock cap, use
|
||||||
|
# `with trio.fail_after(N):` INSIDE the test — trio's own
|
||||||
|
# Cancelled machinery handles the timeout cleanly through
|
||||||
|
# the actor nursery without disturbing global state. See
|
||||||
|
# `tests/test_advanced_streaming.py::test_dynamic_pub_sub`'s
|
||||||
|
# module-level NOTE for the canonical pattern.
|
||||||
|
#
|
||||||
|
# CI environments should rely on job-level wall-clock
|
||||||
|
# timeouts (e.g. GitHub Actions `timeout-minutes`) for an
|
||||||
|
# escape hatch on genuinely-stuck suites.
|
||||||
# https://docs.pytest.org/en/stable/reference/reference.html#configuration-options
|
# https://docs.pytest.org/en/stable/reference/reference.html#configuration-options
|
||||||
testpaths = [
|
testpaths = [
|
||||||
'tests'
|
'tests'
|
||||||
|
|
|
||||||
Loading…
Reference in New Issue