Skip to content

Commit 3f39091

Browse files
committed
WS4-2
codetracer-python-recorder/tests/python/test_monitoring_events.py: codetracer-python-recorder/tests/rust/print_tracer.rs: design-docs/balanced-call-stack-events-implementation-plan.status.md: Signed-off-by: Tzanko Matev <[email protected]>
1 parent 4f0db6f commit 3f39091

File tree

3 files changed

+187
-22
lines changed

3 files changed

+187
-22
lines changed

codetracer-python-recorder/tests/python/test_monitoring_events.py

Lines changed: 96 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -441,6 +441,102 @@ def test_coroutine_await_records_balanced_events(tmp_path: Path) -> None:
441441
), "Expected coroutine return value 'done' to be recorded"
442442

443443

444+
def test_coroutine_send_and_throw_events_capture_resume_and_exception(tmp_path: Path) -> None:
445+
code = (
446+
"import types\n\n"
447+
"@types.coroutine\n"
448+
"def checkpoint():\n"
449+
" payload = yield 'suspended'\n"
450+
" return payload\n\n"
451+
"async def worker():\n"
452+
" try:\n"
453+
" payload = await checkpoint()\n"
454+
" return f'ok:{payload}'\n"
455+
" except RuntimeError as err:\n"
456+
" return f'err:{err}'\n\n"
457+
"def drive_success():\n"
458+
" coro = worker()\n"
459+
" coro.send(None)\n"
460+
" try:\n"
461+
" coro.send('data')\n"
462+
" except StopIteration:\n"
463+
" pass\n\n"
464+
"def drive_throw():\n"
465+
" coro = worker()\n"
466+
" coro.send(None)\n"
467+
" try:\n"
468+
" coro.throw(RuntimeError('boom'))\n"
469+
" except StopIteration:\n"
470+
" pass\n\n"
471+
"if __name__ == '__main__':\n"
472+
" drive_success()\n"
473+
" drive_throw()\n"
474+
)
475+
script = tmp_path / "script_coroutine_send_throw.py"
476+
script.write_text(code)
477+
478+
out_dir = ensure_trace_dir(tmp_path)
479+
session = codetracer.start(out_dir, format=codetracer.TRACE_JSON, start_on_enter=script)
480+
try:
481+
runpy.run_path(str(script), run_name="__main__")
482+
finally:
483+
codetracer.flush()
484+
codetracer.stop()
485+
486+
parsed = _parse_trace(out_dir)
487+
assert str(script) in parsed.paths
488+
script_path_id = parsed.paths.index(str(script))
489+
490+
worker_fids = [
491+
i
492+
for i, f in enumerate(parsed.functions)
493+
if f["name"] == "worker" and f["path_id"] == script_path_id
494+
]
495+
assert worker_fids, "Expected worker() coroutine to be registered"
496+
worker_fid = worker_fids[0]
497+
498+
worker_calls = [
499+
call for call in parsed.call_records if int(call["function_id"]) == worker_fid
500+
]
501+
assert (
502+
len(worker_calls) == 4
503+
), f"Expected two starts plus resume/throw edges, saw {len(worker_calls)}"
504+
505+
def arg_name(arg: Dict[str, Any]) -> str:
506+
return parsed.varnames[int(arg["variable_id"])]
507+
508+
def decode_text(value: Dict[str, Any]) -> str:
509+
if value.get("kind") == "String":
510+
return value.get("text", "")
511+
if value.get("kind") == "Raw":
512+
return value.get("r", "")
513+
return ""
514+
515+
exception_calls = [
516+
arg
517+
for call in worker_calls
518+
for arg in call.get("args", [])
519+
if arg_name(arg) == "exception"
520+
]
521+
assert exception_calls, "Expected coroutine throw to record an exception argument"
522+
assert any("boom" in decode_text(arg["value"]) for arg in exception_calls)
523+
524+
def recorded_strings() -> List[str]:
525+
values: List[str] = []
526+
for rv in parsed.returns:
527+
rv_value = rv.get("return_value")
528+
if not rv_value:
529+
continue
530+
text = decode_text(rv_value)
531+
if text:
532+
values.append(text)
533+
return values
534+
535+
strings = recorded_strings()
536+
assert "ok:data" in strings, f"Expected successful resume payload, saw {strings}"
537+
assert "err:boom" in strings, f"Expected exception handling result, saw {strings}"
538+
539+
444540
def test_py_unwind_records_exception_return(tmp_path: Path) -> None:
445541
code = (
446542
"def explode():\n"

codetracer-python-recorder/tests/rust/print_tracer.rs

Lines changed: 84 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -65,6 +65,25 @@ static EXCEPTION_HANDLED_COUNT: AtomicUsize = AtomicUsize::new(0);
6565
static C_RETURN_COUNT: AtomicUsize = AtomicUsize::new(0);
6666
static C_RAISE_COUNT: AtomicUsize = AtomicUsize::new(0);
6767

68+
fn reset_all_counts() {
69+
LINE_COUNT.store(0, Ordering::SeqCst);
70+
INSTRUCTION_COUNT.store(0, Ordering::SeqCst);
71+
JUMP_COUNT.store(0, Ordering::SeqCst);
72+
BRANCH_COUNT.store(0, Ordering::SeqCst);
73+
PY_START_COUNT.store(0, Ordering::SeqCst);
74+
PY_RESUME_COUNT.store(0, Ordering::SeqCst);
75+
PY_RETURN_COUNT.store(0, Ordering::SeqCst);
76+
PY_YIELD_COUNT.store(0, Ordering::SeqCst);
77+
PY_THROW_COUNT.store(0, Ordering::SeqCst);
78+
PY_UNWIND_COUNT.store(0, Ordering::SeqCst);
79+
RAISE_COUNT.store(0, Ordering::SeqCst);
80+
RERAISE_COUNT.store(0, Ordering::SeqCst);
81+
EXCEPTION_HANDLED_COUNT.store(0, Ordering::SeqCst);
82+
// STOP_ITERATION_COUNT.store(0, Ordering::SeqCst); // Not currently triggered in tests.
83+
C_RETURN_COUNT.store(0, Ordering::SeqCst);
84+
C_RAISE_COUNT.store(0, Ordering::SeqCst);
85+
}
86+
6887
struct CountingTracer;
6988

7089
impl Tracer for CountingTracer {
@@ -313,22 +332,7 @@ impl Tracer for CountingTracer {
313332
#[test]
314333
fn tracer_handles_all_events() {
315334
Python::with_gil(|py| {
316-
LINE_COUNT.store(0, Ordering::SeqCst);
317-
INSTRUCTION_COUNT.store(0, Ordering::SeqCst);
318-
JUMP_COUNT.store(0, Ordering::SeqCst);
319-
BRANCH_COUNT.store(0, Ordering::SeqCst);
320-
PY_START_COUNT.store(0, Ordering::SeqCst);
321-
PY_RESUME_COUNT.store(0, Ordering::SeqCst);
322-
PY_RETURN_COUNT.store(0, Ordering::SeqCst);
323-
PY_YIELD_COUNT.store(0, Ordering::SeqCst);
324-
PY_THROW_COUNT.store(0, Ordering::SeqCst);
325-
PY_UNWIND_COUNT.store(0, Ordering::SeqCst);
326-
RAISE_COUNT.store(0, Ordering::SeqCst);
327-
RERAISE_COUNT.store(0, Ordering::SeqCst);
328-
EXCEPTION_HANDLED_COUNT.store(0, Ordering::SeqCst);
329-
// STOP_ITERATION_COUNT.store(0, Ordering::SeqCst); //ISSUE: We can't figure out how to triger this event
330-
C_RETURN_COUNT.store(0, Ordering::SeqCst);
331-
C_RAISE_COUNT.store(0, Ordering::SeqCst);
335+
reset_all_counts();
332336
if let Err(e) = install_tracer(py, Box::new(CountingTracer)) {
333337
e.print(py);
334338
panic!("Install Tracer failed");
@@ -479,3 +483,67 @@ for _ in only_stop_iter():
479483
);
480484
});
481485
}
486+
487+
#[test]
488+
fn tracer_counts_resume_throw_and_unwind_events() {
489+
Python::with_gil(|py| {
490+
reset_all_counts();
491+
if let Err(e) = install_tracer(py, Box::new(CountingTracer)) {
492+
e.print(py);
493+
panic!("Install Tracer failed");
494+
}
495+
let code = CString::new(
496+
r#"
497+
def ticker():
498+
try:
499+
yield "tick"
500+
yield "tock"
501+
except RuntimeError:
502+
return "handled"
503+
504+
g = ticker()
505+
next(g)
506+
next(g)
507+
try:
508+
g.throw(RuntimeError("boom"))
509+
except StopIteration:
510+
pass
511+
512+
def explode():
513+
raise ValueError("kaboom")
514+
515+
try:
516+
explode()
517+
except ValueError:
518+
pass
519+
"#,
520+
)
521+
.expect("CString::new failed");
522+
if let Err(e) = py.run(code.as_c_str(), None, None) {
523+
e.print(py);
524+
uninstall_tracer(py).ok();
525+
panic!("Python raised an exception");
526+
}
527+
uninstall_tracer(py).unwrap();
528+
assert_eq!(
529+
PY_RESUME_COUNT.load(Ordering::SeqCst),
530+
1,
531+
"expected exactly one PY_RESUME event from next(g)"
532+
);
533+
assert_eq!(
534+
PY_THROW_COUNT.load(Ordering::SeqCst),
535+
1,
536+
"expected exactly one PY_THROW event from g.throw(...)"
537+
);
538+
assert_eq!(
539+
PY_YIELD_COUNT.load(Ordering::SeqCst),
540+
2,
541+
"expected two PY_YIELD events from the generator body"
542+
);
543+
assert_eq!(
544+
PY_UNWIND_COUNT.load(Ordering::SeqCst),
545+
1,
546+
"expected one PY_UNWIND event from explode()"
547+
);
548+
});
549+
}

design-docs/balanced-call-stack-events-implementation-plan.status.md

Lines changed: 7 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -38,12 +38,13 @@
3838
- Verification: `just dev test` passes end-to-end.
3939

4040
### WS4 – Testing & Validation
41-
- **Status:** _In progress_
42-
- Added Python integration tests covering generator yield/resume sequences, `g.throw(...)` exception injection, coroutine awaits (`asyncio.run`) and plain exception unwinds to verify balanced call/return pairs and recorded payloads.
43-
- The new coverage exercises the trace JSON to assert call counts, argument capture (including the synthetic `exception` arg), and recorded return values for unwind paths.
44-
- TODO: extend coverage to async `send()`/`throw()` scenarios and consider rust-side assertions for the integration print tracer if further confidence is needed.
41+
- **Status:** _Completed_
42+
- Added Python integration tests covering generator yield/resume sequences, `g.throw(...)` exception injection, coroutine awaits (`asyncio.run`), and plain exception unwinds to verify balanced call/return pairs and recorded payloads.
43+
- Added `test_coroutine_send_and_throw_events_capture_resume_and_exception` to exercise coroutine `send()` and `throw()` paths, asserting the additional call edges plus the encoded `exception` argument and final return payloads.
44+
- Extended `tests/rust/print_tracer.rs` with a focused scenario (`tracer_counts_resume_throw_and_unwind_events`) to prove that `PY_RESUME`, `PY_THROW`, `PY_YIELD`, and `PY_UNWIND` fire the expected number of times for a simple generator/unwind script.
45+
- Verification: `just dev test` (maturin develop + cargo nextest + pytest) now passes end-to-end.
4546

4647
## Next Checkpoints
47-
1. Extend WS4 coverage to additional async edge cases (e.g., `send()`/`throw()` on coroutines) and consider verifying `print_tracer` output in Rust.
48+
1. Monitor nightly runs for regressions around generator/coroutine call balancing and expand coverage again if new CPython events appear.
4849
2. Document any telemetry/logging updates before shipping the feature.
49-
3. Prepare release notes / changelog once WS4 closes out.
50+
3. Prepare release notes / changelog entries summarising the balanced call-stack support once release packaging starts.

0 commit comments

Comments
 (0)