Add prompt-io entries for gh #470 latency work
Log the AI-assisted session per the NLNet generative-AI policy: prompt, profiling findings, per-file diff pointers, measured results and the unimplemented `pdbp`/`platformdirs` deferral follow-ups. (this patch was generated in some part by [`claude-code`][claude-code-gh]) [claude-code-gh]: https://github.com/anthropics/claude-codeboot_latency_470
parent
0a97dd4e71
commit
7f98a5801e
|
|
@ -0,0 +1,83 @@
|
||||||
|
---
|
||||||
|
model: claude-fable-5
|
||||||
|
service: claude
|
||||||
|
session: b6b42e23-0454-4d9b-be1c-0a89d65aed1b
|
||||||
|
timestamp: 2026-07-02T15:56:26Z
|
||||||
|
git_ref: 65bf9df5
|
||||||
|
scope: code
|
||||||
|
substantive: true
|
||||||
|
raw_file: 20260702T155626Z_65bf9df5_prompt_io.raw.md
|
||||||
|
---
|
||||||
|
|
||||||
|
## Prompt
|
||||||
|
|
||||||
|
From `ai/prompt-io/prompts/issue_470.md`:
|
||||||
|
|
||||||
|
> attempt to resolve
|
||||||
|
> https://github.com/goodboy/tractor/issues/470
|
||||||
|
> do it with /open-wkt, ensure you /run-tests on all
|
||||||
|
> changes
|
||||||
|
|
||||||
|
(plus a hard pause-for-human-review deadline of
|
||||||
|
12:50PM EST.)
|
||||||
|
|
||||||
|
Issue #470 asks to trim the ~0.42s `import tractor`
|
||||||
|
cost — which dominates per-actor spawn latency on the
|
||||||
|
`trio` backend — by lazy-importing heavy/optional deps
|
||||||
|
(`pdbp`, `stackscope`, `multiaddr`, + audit of
|
||||||
|
`colorlog`/`bidict`/`wrapt`/`setproctitle`).
|
||||||
|
|
||||||
|
## Response summary
|
||||||
|
|
||||||
|
Profiling showed the issue's dep-list only accounted
|
||||||
|
for ~20ms; the dominant cost (~244ms) was
|
||||||
|
`log.get_logger()`'s `get_caller_mod()` calling
|
||||||
|
`inspect.stack()` at module level in ~39 modules —
|
||||||
|
each call walks every stack frame (deep during nested
|
||||||
|
imports) and scans `sys.modules` per frame via
|
||||||
|
`inspect.getmodule()`.
|
||||||
|
|
||||||
|
Changes, in impact order:
|
||||||
|
|
||||||
|
1. `get_caller_mod()` -> `sys._getframe()` +
|
||||||
|
`f_globals['__name__']` `sys.modules` lookup
|
||||||
|
(~240ms saved).
|
||||||
|
2. Issue's lazy-import checklist: `bidict`,
|
||||||
|
`multiaddr`, `colorlog`, `wrapt` moved to
|
||||||
|
`TYPE_CHECKING`/function-local imports;
|
||||||
|
`platformdirs` function-local; `asyncio` +
|
||||||
|
`.to_asyncio` deferred out of the `devx.debug` +
|
||||||
|
`spawn._entry` eager paths (~15ms saved).
|
||||||
|
3. PEP 562 `__getattr__` on `tractor/__init__.py`
|
||||||
|
preserving public `tractor.to_asyncio` attr access.
|
||||||
|
|
||||||
|
Results: `import tractor` 0.42s -> ~0.145s (~65%);
|
||||||
|
sequential `start_actor` latency 0.40-0.44s ->
|
||||||
|
~0.179s/actor. `pdbp` (needs `_repl.py` class-base
|
||||||
|
restructure) + `platformdirs` (needs
|
||||||
|
`UDSAddress.def_bindspace` protocol rework) documented
|
||||||
|
as follow-ups.
|
||||||
|
|
||||||
|
## Files changed
|
||||||
|
|
||||||
|
- `tractor/log.py` — `get_caller_mod()` perf fix +
|
||||||
|
lazy `colorlog`
|
||||||
|
- `tractor/__init__.py` — PEP 562 lazy `to_asyncio`
|
||||||
|
- `tractor/discovery/_addr.py` — `bidict` ->
|
||||||
|
`TYPE_CHECKING`
|
||||||
|
- `tractor/discovery/_multiaddr.py` — lazy `multiaddr`
|
||||||
|
- `tractor/ipc/_tcp.py`, `tractor/ipc/_uds.py` —
|
||||||
|
`Multiaddr` -> `TYPE_CHECKING`
|
||||||
|
- `tractor/runtime/_state.py` — lazy `platformdirs`
|
||||||
|
- `tractor/devx/_frame_stack.py` — lazy `pdbp` +
|
||||||
|
`wrapt`
|
||||||
|
- `tractor/devx/debug/_trace.py`,
|
||||||
|
`tractor/devx/debug/_tty_lock.py` — lazy `asyncio` +
|
||||||
|
`.to_asyncio`
|
||||||
|
- `tractor/spawn/_entry.py` — lazy
|
||||||
|
`run_as_asyncio_guest`
|
||||||
|
|
||||||
|
## Human edits
|
||||||
|
|
||||||
|
None yet — pending user review at the 12:50PM EST
|
||||||
|
pause gate (test-suite results reported in-session).
|
||||||
|
|
@ -0,0 +1,122 @@
|
||||||
|
---
|
||||||
|
model: claude-fable-5
|
||||||
|
service: claude
|
||||||
|
timestamp: 2026-07-02T15:56:26Z
|
||||||
|
git_ref: 65bf9df5
|
||||||
|
diff_cmd: git diff main..wkt/boot_latency_470
|
||||||
|
---
|
||||||
|
|
||||||
|
# Raw AI output — gh #470 `import tractor` latency trim
|
||||||
|
|
||||||
|
All generated code is committed on the
|
||||||
|
`wkt/boot_latency_470` branch; per diff-ref mode each
|
||||||
|
file's content is referenced via its diff instead of
|
||||||
|
copied verbatim.
|
||||||
|
|
||||||
|
## Profiling findings (verbatim analysis output)
|
||||||
|
|
||||||
|
Baseline: `import tractor` ~0.39-0.42s wall.
|
||||||
|
|
||||||
|
`python -X importtime` + `cProfile` traced the cost NOT
|
||||||
|
primarily to third-party deps (the issue's hypothesis)
|
||||||
|
but to `tractor/log.py:get_logger()` calling
|
||||||
|
`get_caller_mod()` -> `inspect.stack()` at module level
|
||||||
|
in ~39 tractor modules:
|
||||||
|
|
||||||
|
- `inspect.stack()` builds `FrameInfo` (incl. src-file
|
||||||
|
and line-context resolution) for EVERY frame on the
|
||||||
|
stack; during nested imports the stack is dozens of
|
||||||
|
importlib frames deep.
|
||||||
|
- each `FrameInfo` resolution calls
|
||||||
|
`inspect.getmodule()` which scans all of
|
||||||
|
`sys.modules` per frame (1.4M `ismodule()` calls in
|
||||||
|
one profiled import).
|
||||||
|
- aggregate: ~244ms of tractor-own module "self" time
|
||||||
|
vs ~20ms for ALL the issue-listed third-party deps
|
||||||
|
(`pdbp` ~10ms, `bidict` ~4.5ms, `multiaddr` ~3.5ms,
|
||||||
|
`wrapt`/`colorlog` ~1ms each); `trio` itself is
|
||||||
|
~70-100ms and unavoidable.
|
||||||
|
|
||||||
|
## Generated changes
|
||||||
|
|
||||||
|
> `git diff main..wkt/boot_latency_470 -- tractor/log.py`
|
||||||
|
|
||||||
|
`get_caller_mod()` rewritten from `inspect.stack()` +
|
||||||
|
`inspect.getmodule()` to `sys._getframe(frames_up)` +
|
||||||
|
`frame.f_globals['__name__']` -> `sys.modules` lookup
|
||||||
|
(O(1) vs O(stack x sys.modules)). Unused `inspect`
|
||||||
|
imports dropped; `FrameType` imported from `types`.
|
||||||
|
Also `colorlog` lazy-imported inside
|
||||||
|
`get_console_log()`.
|
||||||
|
|
||||||
|
> `git diff main..wkt/boot_latency_470 -- tractor/discovery/_addr.py`
|
||||||
|
|
||||||
|
`bidict` import moved under `TYPE_CHECKING`
|
||||||
|
(annotation-only use; `_address_types` is a plain dict
|
||||||
|
literal).
|
||||||
|
|
||||||
|
> `git diff main..wkt/boot_latency_470 -- tractor/discovery/_multiaddr.py`
|
||||||
|
|
||||||
|
`from __future__ import annotations` added; `multiaddr`
|
||||||
|
import moved under `TYPE_CHECKING` + function-local
|
||||||
|
imports in `mk_maddr()`/`parse_maddr()`.
|
||||||
|
|
||||||
|
> `git diff main..wkt/boot_latency_470 -- tractor/ipc/_tcp.py tractor/ipc/_uds.py`
|
||||||
|
|
||||||
|
`Multiaddr` imports moved under `TYPE_CHECKING`
|
||||||
|
(annotation-only in both transports).
|
||||||
|
|
||||||
|
> `git diff main..wkt/boot_latency_470 -- tractor/runtime/_state.py`
|
||||||
|
|
||||||
|
`platformdirs` lazy-imported inside `get_rt_dir()`
|
||||||
|
(NOTE: still imported eagerly via
|
||||||
|
`UDSAddress.def_bindspace` class-var eval; see
|
||||||
|
follow-ups).
|
||||||
|
|
||||||
|
> `git diff main..wkt/boot_latency_470 -- tractor/devx/_frame_stack.py`
|
||||||
|
|
||||||
|
`pdbp` + `wrapt` lazy-imported inside
|
||||||
|
`hide_runtime_frames()` / `api_frame()` respectively.
|
||||||
|
|
||||||
|
> `git diff main..wkt/boot_latency_470 -- tractor/devx/debug/_trace.py tractor/devx/debug/_tty_lock.py`
|
||||||
|
|
||||||
|
`asyncio` moved to `TYPE_CHECKING` + call-site local
|
||||||
|
imports (`asyncio.current_task()` sites);
|
||||||
|
`tractor.to_asyncio.run_trio_task_in_future` imports
|
||||||
|
moved into the infected-aio runtime branches.
|
||||||
|
|
||||||
|
> `git diff main..wkt/boot_latency_470 -- tractor/spawn/_entry.py`
|
||||||
|
|
||||||
|
`run_as_asyncio_guest` import moved into the
|
||||||
|
`infect_asyncio=True` branches of `_mp_main()` /
|
||||||
|
`_trio_main()`.
|
||||||
|
|
||||||
|
> `git diff main..wkt/boot_latency_470 -- tractor/__init__.py`
|
||||||
|
|
||||||
|
PEP 562 module `__getattr__` added so
|
||||||
|
`tractor.to_asyncio` attr-access still works (required
|
||||||
|
by `tests/test_child_manages_service_nursery.py` and
|
||||||
|
any downstream user) while keeping `asyncio` off the
|
||||||
|
eager import path.
|
||||||
|
|
||||||
|
## Measured results (verbatim)
|
||||||
|
|
||||||
|
- `import tractor`: 0.39-0.42s -> ~0.145s (~65% cut)
|
||||||
|
- `start_actor` spawn+boot+reg+cancel: ~0.40-0.44s ->
|
||||||
|
~0.179s/actor (n=5 sequential, warm parent)
|
||||||
|
- post-change eager-module check: only `pdbp` +
|
||||||
|
`platformdirs` of the issue's list remain eager.
|
||||||
|
|
||||||
|
## Known follow-ups (not implemented, deadline-bound)
|
||||||
|
|
||||||
|
- `pdbp` (~10ms): still eager via
|
||||||
|
`devx/debug/_repl.py` class bases
|
||||||
|
(`class PdbREPL(pdbp.Pdb)`) + `_tty_lock.py`
|
||||||
|
module-level `@pdbp.hideframe`; needs `_repl`
|
||||||
|
restructure + PEP 562 in `devx.debug.__init__`.
|
||||||
|
- `platformdirs` (~1.5ms): eager via
|
||||||
|
`UDSAddress.def_bindspace: ClassVar = get_rt_dir()`
|
||||||
|
class-body call; needs `Address`-protocol rework of
|
||||||
|
`def_bindspace` to a lazy accessor.
|
||||||
|
- `stackscope` + `setproctitle`: already lazy/absent —
|
||||||
|
no change needed.
|
||||||
Loading…
Reference in New Issue