Skip to content

Commit a7d6f78

Browse files
committed
Remove debug log
1 parent 4774301 commit a7d6f78

File tree

2 files changed

+63
-20
lines changed

2 files changed

+63
-20
lines changed
Lines changed: 60 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,60 @@
1+
# Ghost Stack Bug Fix
2+
3+
## Problem
4+
5+
The ghost unwind feature was producing incorrect native stack traces. When `fast_unwind=True`, the captured stack was missing the top frames (like `valloc`) and showed frames shifted by one position.
6+
7+
## Root Causes
8+
9+
### Bug 1: Returning Return Addresses Instead of Instruction Pointers
10+
11+
The `unw_backtrace()` function returns **instruction pointers (IPs)** - the address where each frame is currently executing. However, ghost_stack was returning **return addresses** - the address where each frame will return TO after it completes.
12+
13+
These are different values:
14+
- IP of frame N = where frame N is executing
15+
- Return address stored in frame N = IP of frame N-1 (the caller)
16+
17+
So returning return addresses produces a stack that is shifted by one frame and missing the topmost frame entirely.
18+
19+
**Location**: `capture_and_install()` and `copy_cached_frames()` in `ghost_stack.cpp`
20+
21+
**Fix**:
22+
1. Added `ip` field to `StackEntry` struct to store both the IP (for returning to caller) and the return_address (for trampoline restoration)
23+
2. Changed output buffer to return `entries_[i].ip` instead of `entries_[i].return_address`
24+
25+
### Bug 2: Off-by-One Error in Frame Walking Loop
26+
27+
The original loop structure was:
28+
```cpp
29+
while (unw_step(&cursor) > 0 && frame_idx < raw_count) {
30+
unw_get_reg(&cursor, UNW_REG_IP, &ip); // Read AFTER stepping
31+
...
32+
}
33+
```
34+
35+
This calls `unw_step()` BEFORE reading frame data. After the skip loop positions the cursor at frame 3, the first `unw_step()` moves to frame 4 before we read anything - skipping frame 3 entirely.
36+
37+
**Fix**: Changed to read-then-step pattern:
38+
```cpp
39+
do {
40+
unw_get_reg(&cursor, UNW_REG_IP, &ip); // Read FIRST
41+
...
42+
step_result = unw_step(&cursor); // Step AFTER
43+
} while (step_result > 0);
44+
```
45+
46+
## Files Modified
47+
48+
- `src/memray/_memray/ghost_stack/src/ghost_stack.cpp`
49+
- `StackEntry` struct: added `ip` field
50+
- `capture_and_install()`: store IP, return IP, fix loop structure
51+
- `copy_cached_frames()`: return IP instead of return_address
52+
53+
## Test
54+
55+
The fix was verified with:
56+
```
57+
python -m pytest tests/integration/test_native_tracking.py -v -s -x -k ceval
58+
```
59+
60+
Both `fast_unwind=False` and `fast_unwind=True` variants now pass and produce correct stack traces with `valloc` and `run_recursive` in the expected positions.

src/memray/_memray/ghost_stack/src/ghost_stack.cpp

Lines changed: 3 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -394,12 +394,7 @@ class GhostStackImpl {
394394
#else
395395
// Linux: use libunwind's unw_backtrace
396396
int ret = unw_backtrace(buffer, static_cast<int>(max_frames));
397-
size_t count = (ret > 0) ? static_cast<size_t>(ret) : 0;
398-
LOG_DEBUG("do_unwind: unw_backtrace returned %zu frames\n", count);
399-
for (size_t i = 0; i < count && i < 10; ++i) {
400-
LOG_DEBUG(" raw frame %zu: ip=%p\n", i, buffer[i]);
401-
}
402-
return count;
397+
return (ret > 0) ? static_cast<size_t>(ret) : 0;
403398
#endif
404399
}
405400

@@ -426,9 +421,6 @@ class GhostStackImpl {
426421
// Thread-Local Instance Management
427422
// ============================================================================
428423

429-
// Global counter for debugging
430-
static std::atomic<int> g_backtrace_call_count{0};
431-
432424
/**
433425
* RAII wrapper for thread-local GhostStackImpl.
434426
*
@@ -441,8 +433,7 @@ struct ThreadLocalInstance {
441433

442434
~ThreadLocalInstance() {
443435
if (ptr) {
444-
LOG_DEBUG("Thread exit: resetting shadow stack (total backtrace calls: %d)\n",
445-
g_backtrace_call_count.load());
436+
LOG_DEBUG("Thread exit: resetting shadow stack\n");
446437
ptr->reset();
447438
delete ptr;
448439
ptr = nullptr;
@@ -501,21 +492,15 @@ static void register_atfork_handler() {
501492
extern "C" {
502493

503494
void ghost_stack_init(ghost_stack_unwinder_t unwinder) {
504-
LOG_DEBUG("ghost_stack_init called\n");
505495
std::call_once(g_init_flag, [unwinder]() {
506496
g_custom_unwinder = unwinder;
507-
LOG_DEBUG("Initialized with %s unwinder\n",
508-
unwinder ? "custom" : "default");
509497
});
510498

511499
// Register fork handler (idempotent, safe to call multiple times)
512500
register_atfork_handler();
513501
}
514502

515503
size_t ghost_stack_backtrace(void** buffer, size_t size) {
516-
int call_num = g_backtrace_call_count.fetch_add(1) + 1;
517-
LOG_DEBUG("ghost_stack_backtrace called (call #%d, size=%zu)\n", call_num, size);
518-
519504
// Auto-init if needed
520505
std::call_once(g_init_flag, []() {
521506
g_custom_unwinder = nullptr;
@@ -533,9 +518,7 @@ size_t ghost_stack_backtrace(void** buffer, size_t size) {
533518
unwinder_set = true;
534519
}
535520

536-
size_t result = impl.backtrace(buffer, size);
537-
LOG_DEBUG("ghost_stack_backtrace returning %zu frames (call #%d)\n", result, call_num);
538-
return result;
521+
return impl.backtrace(buffer, size);
539522
}
540523

541524
void ghost_stack_reset(void) {

0 commit comments

Comments
 (0)