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": {
|
||||
"allow": [
|
||||
"Bash(date *)",
|
||||
"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 log *)",
|
||||
"Bash(git status)",
|
||||
|
|
@ -23,14 +31,12 @@
|
|||
"Bash(UV_PROJECT_ENVIRONMENT=py* uv sync:*)",
|
||||
"Bash(UV_PROJECT_ENVIRONMENT=py* uv run:*)",
|
||||
"Bash(echo EXIT:$?:*)",
|
||||
"Write(.claude/*commit_msg*)",
|
||||
"Write(.claude/git_commit_msg_LATEST.md)",
|
||||
"Skill(run-tests)",
|
||||
"Skill(close-wkt)",
|
||||
"Skill(open-wkt)",
|
||||
"Skill(prompt-io)"
|
||||
"Bash(echo \"EXIT=$?\")",
|
||||
"Read(//tmp/**)"
|
||||
],
|
||||
"deny": [],
|
||||
"ask": []
|
||||
}
|
||||
},
|
||||
"prefersReducedMotion": false,
|
||||
"outputStyle": "default"
|
||||
}
|
||||
|
|
|
|||
|
|
@ -229,3 +229,69 @@ Unlike asyncio, trio allows checkpoints in
|
|||
that does `await` can itself be cancelled (e.g.
|
||||
by nursery shutdown). Watch for cleanup code that
|
||||
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:
|
||||
|
||||
```sh
|
||||
# 1. kill test zombies scoped to THIS repo's python only
|
||||
# (don't pkill by bare pattern — that'd nuke legit
|
||||
# long-running tractor apps like piker)
|
||||
pkill -f "$(pwd)/py[0-9]*/bin/python.*_actor_child_main|subint-forkserv"
|
||||
sleep 0.3
|
||||
pkill -9 -f "$(pwd)/py[0-9]*/bin/python.*_actor_child_main|subint-forkserv" 2>/dev/null
|
||||
# 1. GRACEFUL FIRST (tractor is structured concurrent — it
|
||||
# catches SIGINT as an OS-cancel in `_trio_main` and
|
||||
# cascades Portal.cancel_actor via IPC to every descendant.
|
||||
# So always try SIGINT first with a bounded timeout; only
|
||||
# escalate to SIGKILL if graceful cleanup doesn't complete).
|
||||
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:
|
||||
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
|
||||
|
||||
# 4. re-verify
|
||||
# 6. re-verify
|
||||
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`,
|
||||
`trio.TooSlowError`, or `pexpect.TIMEOUT` and you didn't
|
||||
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
|
||||
run: >
|
||||
uv run
|
||||
pytest tests/ -rsx
|
||||
pytest
|
||||
tests/
|
||||
-rsx
|
||||
--spawn-backend=${{ matrix.spawn_backend }}
|
||||
--tpt-proto=${{ matrix.tpt_proto }}
|
||||
--capture=fd
|
||||
# ^XXX^ can't work with --spawn-method=main_thread_forkserver
|
||||
|
||||
# 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
|
||||
# TODO: maybe some of these layout choices?
|
||||
# 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",
|
||||
]
|
||||
repl = [
|
||||
"pyperclip>=1.9.0",
|
||||
"prompt-toolkit>=3.0.50",
|
||||
"xonsh>=0.22.8",
|
||||
"xonsh>=0.23.0",
|
||||
"psutil>=7.0.0",
|
||||
]
|
||||
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' }
|
||||
# ^ https://github.com/xonsh/xonsh/pull/6048
|
||||
# xonsh = { git = 'https://github.com/xonsh/xonsh.git', branch = 'main' }
|
||||
xonsh = { path = "../xonsh", editable = true }
|
||||
# xonsh = { path = "../xonsh", editable = true }
|
||||
|
||||
# [tool.uv.sources.pdbp]
|
||||
# XXX, in case we need to tmp patch again.
|
||||
|
|
@ -193,7 +199,35 @@ all_bullets = true
|
|||
|
||||
[tool.pytest.ini_options]
|
||||
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
|
||||
testpaths = [
|
||||
'tests'
|
||||
|
|
|
|||
Loading…
Reference in New Issue