Skip to content

Commit ca5277c

Browse files
gh-157660: Fix stale TLBC caches in _remote_debugging (#157732)
* gh-157660: Fix stale TLBC caches in _remote_debugging `profiling.sampling` reporting errors or incorrect line numbers in free-threaded builds when a thread-local bytecode array grows or gains entries after being cached. * gh-157660: Retry transient sampling races in TLBC tests --------- Co-authored-by: Pablo Galindo Salgado <Pablogsal@gmail.com>
1 parent a4eb936 commit ca5277c

3 files changed

Lines changed: 145 additions & 3 deletions

File tree

‎Lib/test/test_external_inspection.py‎

Lines changed: 121 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2327,6 +2327,127 @@ def get_trace_with_opcodes(pid):
23272327
location.col_offset, location.end_col_offset)
23282328
self.assertIn(actual, valid_locations)
23292329

2330+
@skip_if_not_supported
2331+
@unittest.skipIf(sys._is_gil_enabled(), "Requires free-threading")
2332+
@unittest.skipIf(
2333+
sys.platform == "linux" and not PROCESS_VM_READV_SUPPORTED,
2334+
"Requires process_vm_readv",
2335+
)
2336+
def test_tlbc_cache_refresh_after_growth(self):
2337+
# Reproducer from gh-157660.
2338+
script = textwrap.dedent("""\
2339+
import os, threading
2340+
from _remote_debugging import RemoteUnwinder
2341+
from test import support
2342+
2343+
go = threading.Event()
2344+
stop = threading.Event()
2345+
2346+
def leaf():
2347+
stop.wait()
2348+
2349+
def wait_for_leaf_frames(u, expected_count):
2350+
for _ in support.sleeping_retry(
2351+
support.SHORT_TIMEOUT,
2352+
f"Expected {expected_count} leaf frames",
2353+
):
2354+
try:
2355+
traces = u.get_stack_trace()
2356+
except RuntimeError as exc:
2357+
if str(exc) != "Failed to parse initial frame in chain":
2358+
raise
2359+
continue
2360+
count = sum(
2361+
f.funcname == "leaf"
2362+
for i in traces
2363+
for t in i.threads for f in t.frame_info
2364+
)
2365+
if count == expected_count:
2366+
return
2367+
2368+
threading.Thread(target=leaf, daemon=True).start()
2369+
for _ in range(16):
2370+
threading.Thread(target=stop.wait, daemon=True).start()
2371+
threading.Thread(target=lambda: (go.wait(), leaf()), daemon=True).start()
2372+
2373+
u = RemoteUnwinder(os.getpid(), all_threads=True, cache_frames=False)
2374+
wait_for_leaf_frames(u, 1)
2375+
go.set()
2376+
wait_for_leaf_frames(u, 2)
2377+
""")
2378+
result = subprocess.run(
2379+
[sys.executable, "-X", "gil=0", "-X", "tlbc=1", "-c", script],
2380+
capture_output=True,
2381+
text=True,
2382+
timeout=SHORT_TIMEOUT,
2383+
)
2384+
self.assertEqual(
2385+
result.returncode, 0,
2386+
f"stdout: {result.stdout}\nstderr: {result.stderr}",
2387+
)
2388+
2389+
@skip_if_not_supported
2390+
@unittest.skipIf(sys._is_gil_enabled(), "Requires free-threading")
2391+
@unittest.skipIf(
2392+
sys.platform == "linux" and not PROCESS_VM_READV_SUPPORTED,
2393+
"Requires process_vm_readv",
2394+
)
2395+
def test_tlbc_cache_refresh_after_slot_fill(self):
2396+
# Reproducer from gh-157660.
2397+
script = textwrap.dedent("""\
2398+
import os, threading
2399+
from _remote_debugging import RemoteUnwinder
2400+
2401+
go = threading.Event()
2402+
stop = threading.Event()
2403+
2404+
def leaf():
2405+
stop.wait()
2406+
2407+
from test import support
2408+
2409+
def lines(u, expected_count):
2410+
for _ in support.sleeping_retry(
2411+
support.SHORT_TIMEOUT,
2412+
f"Expected {expected_count} leaf frames",
2413+
):
2414+
try:
2415+
traces = u.get_stack_trace()
2416+
except RuntimeError as exc:
2417+
if str(exc) != "Failed to parse initial frame in chain":
2418+
raise
2419+
continue
2420+
result = sorted(
2421+
f.location.lineno
2422+
for i in traces
2423+
for t in i.threads for f in t.frame_info
2424+
if f.funcname == "leaf"
2425+
)
2426+
# A new frame can still point at the function definition.
2427+
if (len(result) == expected_count and
2428+
leaf.__code__.co_firstlineno not in result):
2429+
return result
2430+
2431+
threading.Thread(target=leaf, daemon=True).start()
2432+
threading.Thread(target=lambda: (go.wait(), leaf()), daemon=True).start()
2433+
u = RemoteUnwinder(os.getpid(), all_threads=True, cache_frames=False)
2434+
before = lines(u, 1)
2435+
assert before == [8], before
2436+
go.set()
2437+
cached = lines(u, 2)
2438+
assert cached == [8, 8], cached
2439+
""")
2440+
result = subprocess.run(
2441+
[sys.executable, "-X", "gil=0", "-X", "tlbc=1", "-c", script],
2442+
capture_output=True,
2443+
text=True,
2444+
timeout=SHORT_TIMEOUT,
2445+
)
2446+
self.assertEqual(
2447+
result.returncode, 0,
2448+
f"stdout: {result.stdout}\nstderr: {result.stderr}",
2449+
)
2450+
23302451

23312452
class TestUnsupportedPlatformHandling(unittest.TestCase):
23322453
@unittest.skipIf(
Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,2 @@
1+
Fix :mod:`profiling.sampling` reporting errors or incorrect line numbers in free-threaded
2+
builds when a thread-local bytecode array grows or gains entries after being cached.

‎Modules/_remote_debugging/code_objects.c‎

Lines changed: 22 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -32,9 +32,12 @@ get_tlbc_cache_entry(RemoteUnwinderObject *self, uintptr_t code_addr, uint32_t c
3232
TLBCCacheEntry *entry = _Py_hashtable_get(self->tlbc_cache, key);
3333

3434
if (entry && entry->generation != current_generation) {
35-
// Entry is stale, remove it by setting to NULL
36-
_Py_hashtable_set(self->tlbc_cache, key, NULL);
37-
entry = NULL;
35+
// Entry is stale, remove it from the cache and destroy it
36+
TLBCCacheEntry *old = _Py_hashtable_steal(self->tlbc_cache, key);
37+
if (old != NULL) {
38+
tlbc_cache_entry_destroy(old);
39+
}
40+
return NULL;
3841
}
3942

4043
return entry;
@@ -449,6 +452,22 @@ parse_code_object(RemoteUnwinderObject *unwinder,
449452
tlbc_entry = get_tlbc_cache_entry(unwinder, real_address, unwinder->tlbc_generation);
450453
}
451454

455+
if (tlbc_entry && ctx->tlbc_index >= 0) {
456+
uintptr_t *entries = (uintptr_t *)((char *)tlbc_entry->tlbc_array + sizeof(Py_ssize_t));
457+
if (ctx->tlbc_index >= tlbc_entry->tlbc_array_size ||
458+
entries[ctx->tlbc_index] == 0) {
459+
TLBCCacheEntry *old = _Py_hashtable_steal(unwinder->tlbc_cache, (void *)real_address);
460+
if (old != NULL) {
461+
tlbc_cache_entry_destroy(old);
462+
}
463+
if (!cache_tlbc_array(unwinder, real_address, real_address + unwinder->debug_offsets.code_object.co_tlbc,
464+
unwinder->tlbc_generation)) {
465+
goto error;
466+
}
467+
tlbc_entry = get_tlbc_cache_entry(unwinder, real_address, unwinder->tlbc_generation);
468+
}
469+
}
470+
452471
// Validate tlbc_index and check TLBC cache
453472
if (tlbc_entry) {
454473
// Validate index bounds (also catches negative values since tlbc_index is signed)

0 commit comments

Comments
 (0)