Skip to content

Commit 096b619

Browse files
authored
Implement trace/profile events and opcode tracing for generators (RustPython#7268)
- Add TraceEvent::Exception and Opcode variants with profile filtering - Extract dispatch_traced_frame helper for Call/Return trace events - Fire exception trace on new raises, SEND StopIteration, FOR_ITER StopIteration - Fire opcode trace events gated by f_trace_opcodes - Move prev_line to FrameState for persistence across generator suspend/resume - Reset prev_line in gen_throw for correct LINE monitoring after yield - Add per-code event mask (events_for_code) to prevent unrelated code instrumentation - Remove expectedFailure markers from test_bdb (5) and test_sys_setprofile (14)
1 parent dd7c4d2 commit 096b619

7 files changed

Lines changed: 167 additions & 79 deletions

File tree

.cspell.dict/cpython.txt

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@ carg
2828
cellarg
2929
cellvar
3030
cellvars
31+
ceval
3132
cfield
3233
CLASSDEREF
3334
classdict

Lib/test/test_bdb.py

Lines changed: 0 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -614,7 +614,6 @@ def test_step_next_on_last_statement(self):
614614
with TracerRun(self) as tracer:
615615
tracer.runcall(tfunc_main)
616616

617-
@unittest.expectedFailure # TODO: RUSTPYTHON; AssertionError: All paired tuples have not been processed, the last one was number 1 [('next',), ('quit',)]
618617
def test_stepinstr(self):
619618
self.expect_set = [
620619
('line', 2, 'tfunc_main'), ('stepinstr', ),
@@ -1084,7 +1083,6 @@ def func():
10841083
with TracerRun(self) as tracer:
10851084
tracer.runcall(tfunc_import)
10861085

1087-
@unittest.expectedFailure # TODO: RUSTPYTHON; Error in atexit._run_exitfuncs
10881086
def test_next_until_return_in_generator(self):
10891087
# Issue #16596.
10901088
# Check that set_next(), set_until() and set_return() do not treat the
@@ -1126,7 +1124,6 @@ def main():
11261124
with TracerRun(self) as tracer:
11271125
tracer.runcall(tfunc_import)
11281126

1129-
@unittest.expectedFailure # TODO: RUSTPYTHON; Error in atexit._run_exitfuncs
11301127
def test_next_command_in_generator_for_loop(self):
11311128
# Issue #16596.
11321129
code = """
@@ -1158,7 +1155,6 @@ def main():
11581155
with TracerRun(self) as tracer:
11591156
tracer.runcall(tfunc_import)
11601157

1161-
@unittest.expectedFailure # TODO: RUSTPYTHON; Error in atexit._run_exitfuncs
11621158
def test_next_command_in_generator_with_subiterator(self):
11631159
# Issue #16596.
11641160
code = """
@@ -1190,7 +1186,6 @@ def main():
11901186
with TracerRun(self) as tracer:
11911187
tracer.runcall(tfunc_import)
11921188

1193-
@unittest.expectedFailure # TODO: RUSTPYTHON; Error in atexit._run_exitfuncs
11941189
def test_return_command_in_generator_with_subiterator(self):
11951190
# Issue #16596.
11961191
code = """

Lib/test/test_sys_setprofile.py

Lines changed: 0 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -108,7 +108,6 @@ def f(p):
108108
(1, 'return', f_ident),
109109
])
110110

111-
@unittest.expectedFailure # TODO: RUSTPYTHON; [(1, 'call', (112, 'f'))]
112111
def test_exception(self):
113112
def f(p):
114113
1/0
@@ -135,7 +134,6 @@ def f(p):
135134
(1, 'return', f_ident),
136135
])
137136

138-
@unittest.expectedFailure # TODO: RUSTPYTHON; [(1, 'call', (138, 'f'))]
139137
def test_nested_exception(self):
140138
def f(p):
141139
1/0
@@ -147,7 +145,6 @@ def f(p):
147145
(1, 'return', f_ident),
148146
])
149147

150-
@unittest.expectedFailure # TODO: RUSTPYTHON; (1, 'return', (151, 'g'))]
151148
def test_exception_in_except_clause(self):
152149
def f(p):
153150
1/0
@@ -167,7 +164,6 @@ def g(p):
167164
(1, 'return', g_ident),
168165
])
169166

170-
@unittest.expectedFailure # TODO: RUSTPYTHON; (1, 'falling through', (170, 'g'))]
171167
def test_exception_propagation(self):
172168
def f(p):
173169
1/0
@@ -183,7 +179,6 @@ def g(p):
183179
(1, 'return', g_ident),
184180
])
185181

186-
@unittest.expectedFailure # TODO: RUSTPYTHON; [(1, 'call', (183, 'f'))]
187182
def test_raise_twice(self):
188183
def f(p):
189184
try: 1/0
@@ -193,7 +188,6 @@ def f(p):
193188
(1, 'return', f_ident),
194189
])
195190

196-
@unittest.expectedFailure # TODO: RUSTPYTHON; [(1, 'call', (192, 'f'))]
197191
def test_raise_reraise(self):
198192
def f(p):
199193
try: 1/0
@@ -203,7 +197,6 @@ def f(p):
203197
(1, 'return', f_ident),
204198
])
205199

206-
@unittest.expectedFailure # TODO: RUSTPYTHON; [(1, 'call', (201, 'f'))]
207200
def test_raise(self):
208201
def f(p):
209202
raise Exception()
@@ -212,7 +205,6 @@ def f(p):
212205
(1, 'return', f_ident),
213206
])
214207

215-
@unittest.expectedFailure # TODO: RUSTPYTHON; (5, 'call', (209, 'f'))]
216208
def test_distant_exception(self):
217209
def f():
218210
1/0
@@ -297,7 +289,6 @@ def f(p):
297289
(1, 'return', f_ident),
298290
])
299291

300-
@unittest.expectedFailure # TODO: RUSTPYTHON; [(1, 'call', (293, 'f'))]
301292
def test_basic_exception(self):
302293
def f(p):
303294
1/0
@@ -315,7 +306,6 @@ def f(p):
315306
(1, 'return', f_ident),
316307
])
317308

318-
@unittest.expectedFailure # TODO: RUSTPYTHON; (5, 'call', (310, 'f'))]
319309
def test_distant_exception(self):
320310
def f():
321311
1/0
@@ -354,7 +344,6 @@ def f(p):
354344
(1, 'return', f_ident)])
355345

356346
# Test an invalid call (bpo-34126)
357-
@unittest.expectedFailure # TODO: RUSTPYTHON; [(1, 'call', (348, 'f'))]
358347
def test_unbound_method_no_args(self):
359348
def f(p):
360349
dict.get()
@@ -363,7 +352,6 @@ def f(p):
363352
(1, 'return', f_ident)])
364353

365354
# Test an invalid call (bpo-34126)
366-
@unittest.expectedFailure # TODO: RUSTPYTHON; [(1, 'call', (356, 'f'))]
367355
def test_unbound_method_invalid_args(self):
368356
def f(p):
369357
dict.get(print, 42)
@@ -372,7 +360,6 @@ def f(p):
372360
(1, 'return', f_ident)])
373361

374362
# Test an invalid call (bpo-34125)
375-
@unittest.expectedFailure # TODO: RUSTPYTHON; [(1, 'call', (365, 'f'))]
376363
def test_unbound_method_no_keyword_args(self):
377364
kwargs = {}
378365
def f(p):
@@ -382,7 +369,6 @@ def f(p):
382369
(1, 'return', f_ident)])
383370

384371
# Test an invalid call (bpo-34125)
385-
@unittest.expectedFailure # TODO: RUSTPYTHON; [(1, 'call', (374, 'f'))]
386372
def test_unbound_method_invalid_keyword_args(self):
387373
kwargs = {}
388374
def f(p):

crates/vm/src/frame.rs

Lines changed: 77 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -62,6 +62,10 @@ struct FrameState {
6262
stack: BoxVec<Option<PyObjectRef>>,
6363
/// Cell and free variable references (cellvars + freevars).
6464
cells_frees: Box<[PyCellRef]>,
65+
/// Previous line number for LINE event suppression.
66+
/// Stored here (not on ExecutingFrame) so it persists across
67+
/// generator/coroutine suspend and resume.
68+
prev_line: u32,
6569
}
6670

6771
/// Tracks who owns a frame.
@@ -200,6 +204,7 @@ impl Frame {
200204
let state = FrameState {
201205
stack: BoxVec::new(code.max_stackdepth as usize),
202206
cells_frees,
207+
prev_line: 0,
203208
};
204209

205210
Self {
@@ -383,7 +388,6 @@ impl Py<Frame> {
383388
object: self,
384389
state: &mut state,
385390
monitoring_mask: 0,
386-
prev_line: 0,
387391
};
388392
f(exec)
389393
}
@@ -430,7 +434,6 @@ impl Py<Frame> {
430434
object: self,
431435
state: &mut state,
432436
monitoring_mask: 0,
433-
prev_line: 0,
434437
};
435438
exec.yield_from_target().map(PyObject::to_owned)
436439
}
@@ -467,8 +470,6 @@ struct ExecutingFrame<'a> {
467470
state: &'a mut FrameState,
468471
/// Cached monitoring events mask. Reloaded at Resume instruction only,
469472
monitoring_mask: u32,
470-
/// Previous line number for LINE event suppression.
471-
prev_line: u32,
472473
}
473474

474475
impl fmt::Debug for ExecutingFrame<'_> {
@@ -518,6 +519,23 @@ impl ExecutingFrame<'_> {
518519
}
519520
}
520521

522+
/// Fire 'exception' trace event (sys.settrace) with (type, value, traceback) tuple.
523+
/// Matches `_PyEval_MonitorRaise` → `PY_MONITORING_EVENT_RAISE` →
524+
/// `sys_trace_exception_func` in legacy_tracing.c.
525+
fn fire_exception_trace(&self, exc: &PyBaseExceptionRef, vm: &VirtualMachine) -> PyResult<()> {
526+
if vm.use_tracing.get() && !vm.is_none(&self.object.trace.lock()) {
527+
let exc_type: PyObjectRef = exc.class().to_owned().into();
528+
let exc_value: PyObjectRef = exc.clone().into();
529+
let exc_tb: PyObjectRef = exc
530+
.__traceback__()
531+
.map(|tb| -> PyObjectRef { tb.into() })
532+
.unwrap_or_else(|| vm.ctx.none());
533+
let tuple = vm.ctx.new_tuple(vec![exc_type, exc_value, exc_tb]).into();
534+
vm.trace_event(crate::protocol::TraceEvent::Exception, Some(tuple))?;
535+
}
536+
Ok(())
537+
}
538+
521539
fn run(&mut self, vm: &VirtualMachine) -> PyResult<ExecutionResult> {
522540
flame_guard!(format!(
523541
"Frame::run({obj_name})",
@@ -545,9 +563,9 @@ impl ExecutingFrame<'_> {
545563
Some(Instruction::Resume { .. } | Instruction::InstrumentedResume)
546564
)
547565
&& let Some((loc, _)) = self.code.locations.get(idx)
548-
&& loc.line.get() as u32 != self.prev_line
566+
&& loc.line.get() as u32 != self.state.prev_line
549567
{
550-
self.prev_line = loc.line.get() as u32;
568+
self.state.prev_line = loc.line.get() as u32;
551569
vm.trace_event(crate::protocol::TraceEvent::Line, None)?;
552570
// Trace callback may have changed lasti via set_f_lineno.
553571
// Re-read and restart the loop from the new position.
@@ -575,7 +593,23 @@ impl ExecutingFrame<'_> {
575593
| Instruction::InstrumentedLine
576594
) && let Some((loc, _)) = self.code.locations.get(idx)
577595
{
578-
self.prev_line = loc.line.get() as u32;
596+
self.state.prev_line = loc.line.get() as u32;
597+
}
598+
599+
// Fire 'opcode' trace event for sys.settrace when f_trace_opcodes
600+
// is set. Skip RESUME and ExtendedArg (matching CPython's exclusion
601+
// of these in _Py_call_instrumentation_instruction).
602+
if vm.use_tracing.get()
603+
&& !vm.is_none(&self.object.trace.lock())
604+
&& *self.object.trace_opcodes.lock()
605+
&& !matches!(
606+
op,
607+
Instruction::Resume { .. }
608+
| Instruction::InstrumentedResume
609+
| Instruction::ExtendedArg
610+
)
611+
{
612+
vm.trace_event(crate::protocol::TraceEvent::Opcode, None)?;
579613
}
580614

581615
let result = self.execute_instruction(op, arg, &mut do_extend_arg, vm);
@@ -691,6 +725,13 @@ impl ExecutingFrame<'_> {
691725
}
692726
};
693727

728+
// Fire 'exception' trace event for sys.settrace.
729+
// Only for new raises, not re-raises (matching the
730+
// `error` label that calls _PyEval_MonitorRaise).
731+
if !is_reraise {
732+
self.fire_exception_trace(&exception, vm)?;
733+
}
734+
694735
match handle_exception(self, exception, idx, is_reraise, is_new_raise, vm) {
695736
Ok(None) => {}
696737
Ok(Some(result)) => break Ok(result),
@@ -777,6 +818,12 @@ impl ExecutingFrame<'_> {
777818
exc_tb: PyObjectRef,
778819
) -> PyResult<ExecutionResult> {
779820
self.monitoring_mask = vm.state.monitoring_events.load();
821+
// Reset prev_line so that LINE monitoring events fire even if
822+
// the exception handler is on the same line as the yield point.
823+
// In CPython, _Py_call_instrumentation_line has a special case
824+
// for RESUME: it fires LINE even when prev_line == current_line.
825+
// Since gen_throw bypasses RESUME, we reset prev_line instead.
826+
self.state.prev_line = 0;
780827
if let Some(jen) = self.yield_from_target() {
781828
// Check if the exception is GeneratorExit (type or instance).
782829
// For GeneratorExit, close the sub-iterator instead of throwing.
@@ -2167,7 +2214,10 @@ impl ExecutingFrame<'_> {
21672214
.instrumentation_version
21682215
.load(atomic::Ordering::Acquire);
21692216
if code_ver != global_ver {
2170-
let events = vm.state.monitoring_events.load();
2217+
let events = {
2218+
let state = vm.state.monitoring.lock();
2219+
state.events_for_code(self.code.get_id())
2220+
};
21712221
monitoring::instrument_code(self.code, events);
21722222
self.code
21732223
.instrumentation_version
@@ -2424,6 +2474,12 @@ impl ExecutingFrame<'_> {
24242474
Ok(None)
24252475
}
24262476
PyIterReturn::StopIteration(value) => {
2477+
// Fire 'exception' trace event for StopIteration,
2478+
// matching SEND's exception handling.
2479+
if vm.use_tracing.get() && !vm.is_none(&self.object.trace.lock()) {
2480+
let stop_exc = vm.new_stop_iteration(value.clone());
2481+
self.fire_exception_trace(&stop_exc, vm)?;
2482+
}
24272483
let value = vm.unwrap_or_none(value);
24282484
self.push_value(value);
24292485
self.jump(exit_label);
@@ -2538,7 +2594,10 @@ impl ExecutingFrame<'_> {
25382594
.instrumentation_version
25392595
.load(atomic::Ordering::Acquire);
25402596
if code_ver != global_ver {
2541-
let events = vm.state.monitoring_events.load();
2597+
let events = {
2598+
let state = vm.state.monitoring.lock();
2599+
state.events_for_code(self.code.get_id())
2600+
};
25422601
monitoring::instrument_code(self.code, events);
25432602
self.code
25442603
.instrumentation_version
@@ -2809,8 +2868,8 @@ impl ExecutingFrame<'_> {
28092868
// Fire LINE event only if line changed
28102869
if let Some((loc, _)) = self.code.locations.get(idx) {
28112870
let line = loc.line.get() as u32;
2812-
if line != self.prev_line && line > 0 {
2813-
self.prev_line = line;
2871+
if line != self.state.prev_line && line > 0 {
2872+
self.state.prev_line = line;
28142873
monitoring::fire_line(vm, self.code, offset, line)?;
28152874
}
28162875
}
@@ -3529,7 +3588,13 @@ impl ExecutingFrame<'_> {
35293588
self.push_value(value);
35303589
Ok(true)
35313590
}
3532-
Ok(PyIterReturn::StopIteration(_)) => {
3591+
Ok(PyIterReturn::StopIteration(value)) => {
3592+
// Fire 'exception' trace event for StopIteration, matching
3593+
// FOR_ITER's inline call to _PyEval_MonitorRaise.
3594+
if vm.use_tracing.get() && !vm.is_none(&self.object.trace.lock()) {
3595+
let stop_exc = vm.new_stop_iteration(value);
3596+
self.fire_exception_trace(&stop_exc, vm)?;
3597+
}
35333598
// Skip END_FOR (base or instrumented) and jump to POP_ITER.
35343599
let target_idx = target.0 as usize;
35353600
let jump_target = if let Some(unit) = self.code.instructions.get(target_idx) {

0 commit comments

Comments
 (0)