Skip to content

Commit 8df2106

Browse files
pablogsalpablogsal
committed
Fix frame cache to always re-read current frame for accurate line numbers
The frame cache was returning stale line numbers when execution moved within the same function between samples. By always reading the current frame from memory and only caching parent frames, we get correct line numbers while still benefiting from cache hits on the unchanged call stack. This also skips the expensive stack chunk copying in cache mode since direct memory reads are cheaper when most frames come from cache anyway.
1 parent 2711907 commit 8df2106

File tree

6 files changed

+133
-24
lines changed

6 files changed

+133
-24
lines changed

‎Lib/profiling/sampling/sample.py‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -307,7 +307,7 @@ def sample(
307307
native=native,
308308
gc=gc,
309309
skip_non_matching_threads=skip_non_matching_threads,
310-
collect_stats=realtime_stats # Collect stats when realtime_stats is enabled
310+
collect_stats=realtime_stats,
311311
)
312312
profiler.realtime_stats = realtime_stats
313313

@@ -363,7 +363,7 @@ def sample_live(
363363
native=native,
364364
gc=gc,
365365
skip_non_matching_threads=skip_non_matching_threads,
366-
collect_stats=realtime_stats # Collect stats when realtime_stats is enabled
366+
collect_stats=realtime_stats,
367367
)
368368
profiler.realtime_stats = realtime_stats
369369

‎Lib/test/test_external_inspection.py‎

Lines changed: 76 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -2131,7 +2131,12 @@ def _sample_frames(self, client_socket, unwinder, wait_signal, send_ack, require
21312131
"Test only runs on Linux with process_vm_readv support",
21322132
)
21332133
def test_cache_hit_same_stack(self):
2134-
"""Test that 3 consecutive samples reuse cached frame objects (identity check)."""
2134+
"""Test that consecutive samples reuse cached parent frame objects.
2135+
2136+
The current frame (index 0) is always re-read from memory to get
2137+
updated line numbers, so it may be a different object. Parent frames
2138+
(index 1+) should be identical objects from cache.
2139+
"""
21352140
script_body = """\
21362141
def level3():
21372142
sock.sendall(b"sync1")
@@ -2164,11 +2169,71 @@ def level1():
21642169
self.assertEqual(len(frames1), len(frames2))
21652170
self.assertEqual(len(frames2), len(frames3))
21662171

2167-
# All frames must be identical objects (cache reuse)
2168-
for i, (f1, f2, f3) in enumerate(zip(frames1, frames2, frames3)):
2172+
# Current frame (index 0) is always re-read, so check value equality
2173+
self.assertEqual(frames1[0].funcname, frames2[0].funcname)
2174+
self.assertEqual(frames2[0].funcname, frames3[0].funcname)
2175+
2176+
# Parent frames (index 1+) must be identical objects (cache reuse)
2177+
for i in range(1, len(frames1)):
2178+
f1, f2, f3 = frames1[i], frames2[i], frames3[i]
21692179
self.assertIs(f1, f2, f"Frame {i}: samples 1-2 must be same object")
21702180
self.assertIs(f2, f3, f"Frame {i}: samples 2-3 must be same object")
2171-
self.assertIs(f1, f3, f"Frame {i}: samples 1-3 must be same object")
2181+
2182+
@skip_if_not_supported
2183+
@unittest.skipIf(
2184+
sys.platform == "linux" and not PROCESS_VM_READV_SUPPORTED,
2185+
"Test only runs on Linux with process_vm_readv support",
2186+
)
2187+
def test_line_number_updates_in_same_frame(self):
2188+
"""Test that line numbers are correctly updated when execution moves within a function.
2189+
2190+
When the profiler samples at different points within the same function,
2191+
it must report the correct line number for each sample, not stale cached values.
2192+
"""
2193+
script_body = """\
2194+
def outer():
2195+
inner()
2196+
2197+
def inner():
2198+
sock.sendall(b"line_a"); sock.recv(16)
2199+
sock.sendall(b"line_b"); sock.recv(16)
2200+
sock.sendall(b"line_c"); sock.recv(16)
2201+
sock.sendall(b"line_d"); sock.recv(16)
2202+
2203+
outer()
2204+
"""
2205+
2206+
with self._target_process(script_body) as (p, client_socket, make_unwinder):
2207+
unwinder = make_unwinder(cache_frames=True)
2208+
2209+
frames_a = self._sample_frames(client_socket, unwinder, b"line_a", b"ack", {"inner"})
2210+
frames_b = self._sample_frames(client_socket, unwinder, b"line_b", b"ack", {"inner"})
2211+
frames_c = self._sample_frames(client_socket, unwinder, b"line_c", b"ack", {"inner"})
2212+
frames_d = self._sample_frames(client_socket, unwinder, b"line_d", b"done", {"inner"})
2213+
2214+
self.assertIsNotNone(frames_a)
2215+
self.assertIsNotNone(frames_b)
2216+
self.assertIsNotNone(frames_c)
2217+
self.assertIsNotNone(frames_d)
2218+
2219+
# Get the 'inner' frame from each sample (should be index 0)
2220+
inner_a = frames_a[0]
2221+
inner_b = frames_b[0]
2222+
inner_c = frames_c[0]
2223+
inner_d = frames_d[0]
2224+
2225+
self.assertEqual(inner_a.funcname, "inner")
2226+
self.assertEqual(inner_b.funcname, "inner")
2227+
self.assertEqual(inner_c.funcname, "inner")
2228+
self.assertEqual(inner_d.funcname, "inner")
2229+
2230+
# Line numbers must be different and increasing (execution moves forward)
2231+
self.assertLess(inner_a.lineno, inner_b.lineno,
2232+
"Line B should be after line A")
2233+
self.assertLess(inner_b.lineno, inner_c.lineno,
2234+
"Line C should be after line B")
2235+
self.assertLess(inner_c.lineno, inner_d.lineno,
2236+
"Line D should be after line C")
21722237

21732238
@skip_if_not_supported
21742239
@unittest.skipIf(
@@ -2351,9 +2416,13 @@ def recurse(n):
23512416

23522417
self.assertEqual(len(frames1), len(frames2))
23532418

2354-
# All frames should be identical objects (cache reuse)
2355-
for i, (f1, f2) in enumerate(zip(frames1, frames2)):
2356-
self.assertIs(f1, f2, f"Frame {i}: recursive frames must be same object")
2419+
# Current frame (index 0) is re-read, check value equality
2420+
self.assertEqual(frames1[0].funcname, frames2[0].funcname)
2421+
2422+
# Parent frames (index 1+) should be identical objects (cache reuse)
2423+
for i in range(1, len(frames1)):
2424+
self.assertIs(frames1[i], frames2[i],
2425+
f"Frame {i}: recursive frames must be same object")
23572426

23582427
@skip_if_not_supported
23592428
@unittest.skipIf(

‎Modules/_remote_debugging/frame_cache.c‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -16,7 +16,11 @@ int
1616
frame_cache_init(RemoteUnwinderObject *unwinder)
1717
{
1818
unwinder->frame_cache = PyMem_Calloc(FRAME_CACHE_MAX_THREADS, sizeof(FrameCacheEntry));
19-
return unwinder->frame_cache ? 0 : -1;
19+
if (!unwinder->frame_cache) {
20+
PyErr_NoMemory();
21+
return -1;
22+
}
23+
return 0;
2024
}
2125

2226
void

‎Modules/_remote_debugging/frames.c‎

Lines changed: 43 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -435,8 +435,12 @@ clear_last_profiled_frames(RemoteUnwinderObject *unwinder)
435435
return 0;
436436
}
437437

438-
// Fast path: check if we have a full cache hit (entire stack unchanged)
439-
// Returns: 1 if full hit (frame_info populated), 0 if miss, -1 on error
438+
// Fast path: check if we have a full cache hit (parent stack unchanged)
439+
// A "full hit" means current frame == last profiled frame, so we can reuse
440+
// cached parent frames. We always read the current frame from memory to get
441+
// updated line numbers (the line within a frame can change between samples).
442+
// Returns: 1 if full hit (frame_info populated with current frame + cached parents),
443+
// 0 if miss, -1 on error
440444
static int
441445
try_full_cache_hit(
442446
RemoteUnwinderObject *unwinder,
@@ -463,14 +467,44 @@ try_full_cache_hit(
463467
return 0;
464468
}
465469

466-
// Full hit! Extend frame_info with entire cached list
467-
Py_ssize_t cur_size = PyList_GET_SIZE(frame_info);
468-
int result = PyList_SetSlice(frame_info, cur_size, cur_size, entry->frame_list);
469-
if (result >= 0) {
470-
STATS_INC(unwinder, frame_cache_hits);
471-
STATS_ADD(unwinder, frames_read_from_cache, PyList_GET_SIZE(entry->frame_list));
470+
// Always read the current frame from memory to get updated line number
471+
PyObject *current_frame = NULL;
472+
uintptr_t code_object_addr = 0;
473+
uintptr_t previous_frame = 0;
474+
int parse_result = parse_frame_object(unwinder, &current_frame, frame_addr,
475+
&code_object_addr, &previous_frame);
476+
if (parse_result < 0) {
477+
return -1;
472478
}
473-
return result < 0 ? -1 : 1;
479+
480+
// Add current frame if valid
481+
if (current_frame != NULL) {
482+
if (PyList_Append(frame_info, current_frame) < 0) {
483+
Py_DECREF(current_frame);
484+
return -1;
485+
}
486+
Py_DECREF(current_frame);
487+
STATS_ADD(unwinder, frames_read_from_memory, 1);
488+
}
489+
490+
// Extend with cached parent frames (from index 1 onwards, skipping the current frame)
491+
Py_ssize_t cached_size = PyList_GET_SIZE(entry->frame_list);
492+
if (cached_size > 1) {
493+
PyObject *parent_slice = PyList_GetSlice(entry->frame_list, 1, cached_size);
494+
if (!parent_slice) {
495+
return -1;
496+
}
497+
Py_ssize_t cur_size = PyList_GET_SIZE(frame_info);
498+
int result = PyList_SetSlice(frame_info, cur_size, cur_size, parent_slice);
499+
Py_DECREF(parent_slice);
500+
if (result < 0) {
501+
return -1;
502+
}
503+
STATS_ADD(unwinder, frames_read_from_cache, cached_size - 1);
504+
}
505+
506+
STATS_INC(unwinder, frame_cache_hits);
507+
return 1;
474508
}
475509

476510
// High-level helper: collect frames with cache optimization

‎Modules/_remote_debugging/module.c‎

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -290,7 +290,7 @@ _remote_debugging_RemoteUnwinder___init___impl(RemoteUnwinderObject *self,
290290
#ifdef Py_GIL_DISABLED
291291
if (only_active_thread) {
292292
PyErr_SetString(PyExc_ValueError,
293-
"only_active_thread is not supported when Py_GIL_DISABLED is not defined");
293+
"only_active_thread is not supported in free-threaded builds");
294294
return -1;
295295
}
296296
#endif
@@ -389,7 +389,6 @@ _remote_debugging_RemoteUnwinder___init___impl(RemoteUnwinderObject *self,
389389
#endif
390390

391391
if (cache_frames && frame_cache_init(self) < 0) {
392-
PyErr_NoMemory();
393392
return -1;
394393
}
395394

‎Modules/_remote_debugging/threads.c‎

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -383,9 +383,12 @@ unwind_stack_for_thread(
383383
goto error;
384384
}
385385

386-
if (copy_stack_chunks(unwinder, *current_tstate, &chunks) < 0) {
387-
set_exception_cause(unwinder, PyExc_RuntimeError, "Failed to copy stack chunks");
388-
goto error;
386+
// In cache mode, copying stack chunks is more expensive than direct memory reads
387+
if (!unwinder->cache_frames) {
388+
if (copy_stack_chunks(unwinder, *current_tstate, &chunks) < 0) {
389+
set_exception_cause(unwinder, PyExc_RuntimeError, "Failed to copy stack chunks");
390+
goto error;
391+
}
389392
}
390393

391394
if (unwinder->cache_frames) {

0 commit comments

Comments
 (0)