Skip to content

Commit 4fac0af

Browse files
committed
design: better module identifiers in call stack
design-docs/adr/0014-module-call-event-naming.md: design-docs/module-call-event-naming-implementation-plan.md: Signed-off-by: Tzanko Matev <[email protected]>
1 parent 12a071c commit 4fac0af

File tree

2 files changed

+125
-0
lines changed

2 files changed

+125
-0
lines changed
Lines changed: 55 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,55 @@
1+
# ADR 0014: Module Call Events Report Actual Module Names
2+
3+
- **Status:** Proposed
4+
- **Date:** 2025-10-26
5+
- **Deciders:** codetracer recorder maintainers
6+
- **Consulted:** DX/observability stakeholders, Python runtime SMEs
7+
- **Informed:** Support engineers, product analytics consumers
8+
9+
## Context
10+
- Every Python import executes the target module object under the hood. The recorder hooks `PY_START` for those executions and emits a synthetic “function call” whose name currently comes from `code.co_qualname`.
11+
- For module-level code objects CPython hardcodes `co_name == co_qualname == "<module>"`, so our trace file shows dozens (or hundreds) of `<module>` activations with no indication of which package was imported.
12+
- Trace consumers (CLI visualisations, query tools, and data-engineering pipelines) rely on the recorded function name to surface hot paths, build flame graphs, and attribute time/cost to particular packages. Without module names, users cannot tell whether a slow import belongs to `boto3`, `_distutils_hack`, or their own modules.
13+
- The trace filter engine already resolves module names from filenames / `sys.modules` to power `pkg:*` selectors, but the runtime tracer never reuses that information when assigning `FunctionId`s.
14+
15+
## Problem
16+
- Module import events are indistinguishable in the trace log, making it impossible to attribute import costs, filter specific packages after the fact, or answer “which module executed here?” without cross-referencing filenames manually.
17+
- Because traces only show `<module>`, downstream tools collapse all module-level activations into a single node, hiding per-package behaviour and producing misleading metrics.
18+
- Purely using filenames as a proxy would leak physical layouts (e.g., `/usr/lib/python3.12/site-packages/boto3/__init__.py`) into the user-facing name and fails for zip apps or namespace packages.
19+
20+
## Decision
21+
1. **Introduce a shared module identity helper.**
22+
- Extract the existing module-derivation logic (`module_name_from_roots`, `lookup_module_name`) into a reusable service that can run independent of the filter engine.
23+
- Accept a `CodeObjectWrapper` + `Python<'_>` handle and return a cached module name keyed by (code id, canonical filename). The helper first consults the filter resolution (if available), then repeats the relative-path inference, and finally falls back to `sys.modules` + frame globals (`__name__`) before conceding.
24+
2. **Rewrite `<module>` names as `<{resolved_name}>`.**
25+
- When `RuntimeTracer::ensure_function_id` observes `co_qualname == "<module>"`, it queries the helper for the semantic module name.
26+
- If a valid dotted identifier comes back (e.g., `boto3`, `foo.bar`), the tracer registers the function as `<boto3>` / `<foo.bar>` so downstream tooling still recognises the syntactic angle-bracket convention while learning the package involved.
27+
- If resolution fails or yields garbage (non-identifier characters), the tracer keeps the legacy `<module>` label to avoid fabricating bad data.
28+
3. **Cache aggressively and keep the hot path cheap.**
29+
- Store successful and failed lookups in `HashMap<usize, Option<String>>` keyed by code id so we only touch `sys.modules` or frame globals once per module.
30+
- Reuse the helper from both the runtime tracer and (later) the pure-Python recorder to ensure consistent naming semantics across products.
31+
4. **Document the behaviour.**
32+
- Update the recorder docs to state that module-level call events now show `<module-name>` and call out the limited cases (synthetic filenames, frozen modules, namespace packages) where the fallback remains `<module>`.
33+
34+
## Consequences
35+
- **Pros**
36+
- Import-heavy traces become readable: users immediately know which modules executed without digging through file paths.
37+
- Post-processing / analytics pipelines gain a stable key (the dotted module name) to aggregate import costs or identify slow third-party packages.
38+
- Reusing the existing derivation logic keeps behaviour aligned with trace filters and avoids duplicating heuristics.
39+
- **Cons**
40+
- The tracer must occasionally scan `sys.modules` or inspect frame globals, which would add a small amount of work the first time we see each module. Caching mitigates the steady-state cost.
41+
- Changing the function label alters the textual output of existing traces, so snapshot tests or downstream expectations that explicitly compare against `<module>` need updates.
42+
- **Risks**
43+
- Mis-resolving a module (e.g., due to namespace packages exposing multiple files) could misattribute work to the wrong name. We guard this by preferring explicit `__spec__.name` / `__name__` over path guesses and falling back to `<module>` when ambiguous.
44+
- Frames without real filenames (`<string>`, `<frozen ...>`) still cannot produce a meaningful module name. We explicitly document this to prevent support churn.
45+
- Accessing `sys.modules` must hold the GIL and avoid long-lived Python references; the helper API enforces that discipline.
46+
47+
## Alternatives
48+
- **Keep `<module>` and rely on filenames elsewhere.** Rejected because the filename is not present on every trace consumer surface and is cumbersome for humans.
49+
- **Rewrite module names from filenames only.** Rejected due to incorrect results for namespace packages, zip imports, site-packages bytecode caches, and `.pyc` vs `.py` mismatches.
50+
- **Add a new event field for module name.** Rejected to avoid changing the trace file schema; reusing the existing `function_name` field keeps compat with all tooling.
51+
52+
## References
53+
- `codetracer-python-recorder/src/runtime/tracer/runtime_tracer.rs` (`ensure_function_id`).
54+
- `codetracer-python-recorder/src/runtime/tracer/events.rs` (`register_call_record`).
55+
- `codetracer-python-recorder/src/trace_filter/engine.rs` (current module name derivation & caching).
Lines changed: 70 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,70 @@
1+
# Module Call Event Naming – Implementation Plan
2+
3+
Plan owners: codetracer recorder maintainers
4+
Target ADR: 0014 – Module Call Events Report Actual Module Names
5+
Impacted components: `codetracer-python-recorder/src/runtime/tracer`, `src/runtime/value_capture`, `src/trace_filter`, design docs & user docs
6+
7+
## Goals
8+
- Replace the `<module>` placeholder emitted during module imports with the actual dotted module name (e.g., `<boto3>`, `<foo.bar>`).
9+
- Share a single, cached module identity resolver between trace filtering and runtime event recording so both systems agree on module names.
10+
- Keep the hot path fast by caching module resolutions per code object and falling back to `<module>` only when we genuinely cannot determine the name.
11+
- Provide regression tests proving the trace writer records the new labels for in-project modules, site-packages imports, and namespace packages with real filenames.
12+
13+
## Non-Goals
14+
- Changing the trace file schema or emitting additional fields beyond the function name.
15+
- Reworking how module names feed into configurable trace filters (that behaviour is covered by ADR 0013).
16+
- Retrofitting the pure-Python recorder in this iteration, though the helper should make that future work straightforward.
17+
18+
## Current Gaps
19+
- `RuntimeTracer::ensure_function_id` always uses `code.co_qualname`, which is `<module>` for every top-level module execution.
20+
- Module name derivation logic lives inside `trace_filter::engine` and cannot be reused without duplicating heuristics (relative path stripping, `sys.modules` scan, `.pyc` awareness).
21+
- There is no cache tying `code_id` → module name outside the filter cache, so even if we bolted on ad-hoc lookups we would keep rescanning `sys.modules`.
22+
- No tests assert the textual function name for import events, so regressions would go unnoticed.
23+
24+
## Workstreams
25+
26+
### WS1 – Shared Module Identity Helper
27+
**Scope:** Factor reusable module name derivation ahead of tracer integration.
28+
- Extract `module_name_from_roots`, `lookup_module_name`, normalization helpers, and identifier validation from `trace_filter::engine` into a new module (e.g., `module_identity.rs`) under `src/common` or similar.
29+
- Add APIs:
30+
- `ModuleIdentityResolver::from_sys_path(py) -> Self` to snapshot `sys.path` roots.
31+
- `fn resolve_for_code(&self, py, code, frame_globals_name: Option<&str>) -> Option<String>` that performs (1) cached lookup by code id, (2) relative path inference, (3) `sys.modules` scan, and (4) optional `__name__` override when provided.
32+
- Allow the resolver to accept already-known module names (from `ScopeResolution.module_name`) so we do not recompute them.
33+
- Write focused Rust unit tests that stub out `sys.modules` entries to cover `.py` vs `.pyc` matches, namespace packages (`package/__init__.py`), and failure cases.
34+
- Update `trace_filter::engine` to depend on the new helper rather than its private copy, keeping behaviour identical.
35+
36+
### WS2 – Runtime Tracer Integration
37+
**Scope:** Use the helper to rename `<module>` call events.
38+
- Extend `RuntimeTracer` with a `module_name_cache: HashMap<usize, Option<String>>` (or wrap the helper inside the tracer) and ensure it is cleared when the tracer resets.
39+
- When registering a call:
40+
- Check whether the filter resolution already cached a module name; pass it into the resolver to avoid recomputation.
41+
- Detect module-level code by checking `qualname == "<module>"` (and guard against variants like `"<module>"` with whitespace).
42+
- Ask the helper for a module name; when successful, format the function label as `format!("<{name}>")` before calling `TraceWriter::ensure_function_id`.
43+
- If the helper cannot decide, continue emitting `<module>` to preserve backwards compatibility.
44+
- Consider inspecting the captured frame snapshot (already obtained for argument capture) to pull `globals["__name__"]` as an extra hint when `sys.modules` fails; plumb that optional string into the helper to keep the `ensure_function_id` signature narrow.
45+
- Emit debug logs when we fall back to `<module>` despite having a real filename so troubleshooting remains possible.
46+
47+
### WS3 – Testing, Tooling, and Docs
48+
**Scope:** Prove the behaviour change and explain it to users.
49+
- Add Python integration tests (e.g., `tests/python/test_monitoring_events.py`) that:
50+
- Import a first-party module (`tests/python/support/sample_pkg/__init__.py`) and assert the trace JSON contains `<tests.python.support.sample_pkg>`.
51+
- Import a third-party-like package placed under a temporary directory inserted into `sys.path` to ensure `sys.modules` + relative path fallback works.
52+
- Cover namespace packages or packages that only expose `__spec__.name` to ensure we trust metadata over filesystem guesses.
53+
- Add Rust tests for the resolver cache (verify we only touch `sys.modules` once per module) and for the formatting logic in `ensure_function_id`.
54+
- Update `docs/README.md` (or recorder-specific docs) to mention that module names now appear in angle brackets, along with any troubleshooting guidance for cases where `<module>` persists (synthetic filenames, frozen imports).
55+
- Refresh changelog entries and any CLI snapshot tests that checked for `<module>`.
56+
57+
## Testing Strategy
58+
- `cargo test -p codetracer-python-recorder` to run the new resolver unit tests.
59+
- `just test` to exercise Python integration tests and ensure traces serialize as expected.
60+
- Manual verification script that traces `python - <<'PY' ...` importing `boto3` (or a stub) and inspects the `.trace` file with `runtime_tracing::TraceReader`.
61+
62+
## Risks & Mitigations
63+
- **Performance regressions:** Taking the GIL and scanning `sys.modules` per module could add overhead. Mitigate via per-code caches and by reusing filter-derived names when available.
64+
- **Incorrect attribution:** Namespace packages or reloaded modules might map multiple files to one name. Mitigate by preferring `__spec__.name`/`__name__` and logging whenever multiple candidates compete.
65+
- **Tight coupling with filters:** If the helper accidentally references filter-specific types, it becomes impossible to reuse elsewhere. Keep the helper independent and inject filter results as plain `Option<String>`.
66+
- **Test brittleness:** Snapshot tests referencing `<module>` need refreshing; add helper assertions that look for `<...>` pattern rather than hard-coded `<module>`.
67+
68+
## Open Questions
69+
- Should we expose the resolved module name anywhere else (e.g., as metadata on trace records) to aid scripting? For now we only change the function label, but we might want to surface the raw dotted name later.
70+
- How should we treat modules executed via `runpy.run_module` with `__name__ == "__main__"` but living under a package path? The helper will return `"__main__"`; confirm that is acceptable or consider using the package dotted path derived from filename when `__name__ == "__main__"`.

0 commit comments

Comments
 (0)