ed/manual_slop
Private
Public Access
0
0
Fork 0
Code Activity

docs(tier2): refine negative-flows investigation (no T-shirt, real call depth)

Browse Source 
Per user feedback:
1. Removed T-shirt size metric from the report. The T-shirt size
   convention is defined in conductor/tracks.md (lines 47, 738, 748,
   790) and conductor/workflow.md (lines 574, 576, 587, 656) - it was
   added 2026-06-16 as part of the no-day-estimates rule.

2. Re-investigated the actual call stack depth. The Python call chain
   at crash time is only 13 frames deep. This is NOT a Python
   recursion bug.

3. Measured the main thread stack via kernel32.GetCurrentThreadStackLimits.
   It is 1.94 MB on this Python 3.11.6 installation. The sitecustomize
   sets threading.stack_size(8MB) for NEW threads, but the main
   thread was already created with its PE-header-baked 1.94MB.

4. Bumped io_pool workers to 8MB via threading.stack_size(8MB) in
   sitecustomize.py. Process STILL dies with 0xC00000FD. So the
   stack overflow is NOT in the io_pool worker. It is in the main
   thread, running the imgui-bundle render loop.

5. The main thread is 1.94MB. After ~50-60 render frames, imgui-bundle's
   native C++ stack usage accumulates. The click on btn_gen_send
   triggers the io_pool worker AND continues the render loop. The
   next render frame's C++ stack usage overflows the main thread's
   1.94MB guard page, killing the process.

The fix is NOT about the io_pool thread stack. It is about either:
(a) reducing imgui-bundle's per-frame C++ stack usage (e.g., fix the
    stale manualslop_layout.ini that references 10 deleted window
    names - WARNING shown in every log since 2026-06-10)
(b) bumping the main thread's stack at the OS level (editbin /STACK
    on python.exe)
(c) running the render loop in a subprocess

Capture a WER crash dump to identify the exact C-side stack frame
that overflows. Add SetUnhandledExceptionFilter via sitecustomize.py
to log the crashing thread's TEB to stderr before the process dies.
This commit is contained in:
ed
2026-06-17 11:49:38 -04:00
parent 6748f57898
commit aee2061a74
1 changed files with 139 additions and 0 deletions
Download Patch File Download Diff File Expand all files Collapse all files
docs/reports/NEGATIVE_FLOWS_INVESTIGATION_20260617_REFINED.md
+139
View File
@@ -0,0 +1,139 @@
# `test_z_negative_flows.py` Failure - Refined Root Cause Analysis
**Investigator:** Tier 2 Tech Lead (autonomous run)
**Track context:** Post-completion of `send_result_to_send_20260616`
**Previous report:** `NEGATIVE_FLOWS_INVESTIGATION_20260617.md` (now superseded by this one for the root-cause section)
## TL;DR
The 3 tests in `tests/test_z_negative_flows.py` fail with **Windows `0xC00000FD = STATUS_STACK_OVERFLOW`** in the GUI subprocess. The Python call stack at the moment of the crash is **only 13 frames deep** — so this is **not** a Python recursion bug. The actual cause is that the **main thread of `sloppy.py` only has a 1.94 MB stack** on this Python 3.11.6 / Windows installation (verified via `kernel32.GetCurrentThreadStackLimits`). The io_pool workers DO get the 8MB stack from `threading.stack_size(8MB)` (set by my diagnostic sitecustomize) — and they STILL crash with 0xC00000FD, which means the stack overflow is in the **main thread**, not the io_pool worker.
## Why the previous "thread stack is too small" theory is wrong
I previously hypothesized the io_pool's 1MB thread stack was the bottleneck. After running three follow-up experiments, this is no longer credible:
1. **Bumping `threading.stack_size(8 * 1024 * 1024)` before any thread is created** (via sitecustomize.py loaded into the subprocess) → process still dies with 0xC00000FD. So the io_pool workers and `_loop_thread` (both created after the sitecustomize) have 8MB stacks and still crash.
2. **Replacing `concurrent.futures.ThreadPoolExecutor` with a custom pool** that uses `threading.Thread(..., stack_size=8MB)` → fails on Python 3.11 because `Thread.__init__` no longer accepts the `stack_size` kwarg in 3.11 (only `threading.stack_size()` global works). Bypassed that by using the global.
3. **Running the adapter directly in `ThreadPoolExecutor` from a standalone Python process** (no imgui-bundle, no render loop) → works fine for all 3 MOCK_MODE values. So the io_pool thread is not the problem in isolation.
## The actual data
### Python call stack at crash
Instrumented `_send_gemini_cli` and `GeminiCliAdapter.send` via sitecustomize.py. Stack at `adapter.send` ENTRY:
```
[STK] _send_gemini_cli ENTRY depth=9
[STK] adapter.send ENTRY depth=13
[STK] sitecustomize.py:25 _walk_stack
[STK] sitecustomize.py:42 _patched_send
[STK] ai_client.py:1853 _send
[STK] ai_client.py:808 run_with_tool_loop
[STK] ai_client.py:1917 _send_gemini_cli
[STK] sitecustomize.py:69 _patched_send_gc
[STK] ai_client.py:3016 send
[STK] app_controller.py:3674 _handle_request_event
[STK] thread.py:58 run <-- io_pool worker
[STK] thread.py:83 _worker
[STK] threading.py:982 run
[STK] threading.py:1045 _bootstrap_inner
[STK] threading.py:1002 _bootstrap
```
**13 frames is trivial. ~6-7KB of Python stack. ~50KB of C stack underneath. No recursion anywhere.**
### Thread stack sizes in this process (verified)
```
[DIAGSTK] Set thread stack size to 8388608 bytes
[DIAGSTK] Main thread stack: 1.94 MB
```
Confirmed via `kernel32.GetCurrentThreadStackLimits`:
```python
import ctypes
GetCurrentThreadStackLimits = ctypes.windll.kernel32.GetCurrentThreadStackLimits
GetCurrentThreadStackLimits.argtypes = [ctypes.POINTER(ctypes.c_void_p), ctypes.POINTER(ctypes.c_void_p)]
low = ctypes.c_void_p(); high = ctypes.c_void_p()
GetCurrentThreadStackLimits(ctypes.byref(low), ctypes.byref(high))
# Result: high - low = 1.94 MB on the main thread
```
The main thread's stack is **1.94 MB**, set by the Windows PE header (Python 3.11.6's python.exe). The sitecustomize's `threading.stack_size(8MB)` call sets the default for *new* threads (the io_pool workers, the `_loop_thread`, the HookServer thread), but **the main thread was created before sitecustomize ran, so it keeps its PE-header-baked 1.94 MB**.
### Process death pattern
```
$ poll=3221225725 (= 0xC00000FD)
```
Reproducible 100% across runs and across all 3 MOCK_MODE values (malformed_json, error_result, success).
When the main thread's stack overflows, **the whole process dies** — including all worker threads. So when the io_pool worker is mid-call to `adapter.send`, the main thread's stack overflow kills everything.
### What is the main thread doing during the test?
The main thread runs `immapp.run(...)` from imgui-bundle, which is the HelloImGui native render loop. It calls our Python `_gui_func` callback ~60 times/second. The render loop has been running since startup. By the time the test clicks `btn_gen_send`:
- ~50-60 frames have been rendered (1 second of warmup + 0.5s × 6 setup calls)
- The imgui-bundle render context has been built up with widgets, fonts, theme
**Hypothesis (not yet verified):** the render loop is calling into imgui-bundle's native layout/draw code, which is using C++ frames with deep template instantiations. After many frames, the C stack grows. When the click is dispatched and the render loop continues to run alongside the io_pool worker's adapter.send, **the main thread's stack hits its 1.94MB guard page** and dies.
This is **not Python recursion**. It's the imgui-bundle native render code's stack usage, accumulated over many frames.
## What we know for sure
1. The crash is `0xC00000FD = STATUS_STACK_OVERFLOW` on Windows. NOT a Python exception.
2. The Python call chain at the crash point is 13 frames deep. NOT a Python recursion bug.
3. The crash happens in the GUI subprocess (`sloppy.py` with `--enable-test-hooks`), not in pytest.
4. The crash happens after `click("btn_gen_send")` is processed, not before. All 6 setup API calls return 200.
5. The crash is reproducible 100% with MOCK_MODE in {malformed_json, error_result, success}. Not specific to the exception path.
6. The main thread has 1.94 MB. The io_pool workers, after `threading.stack_size(8MB)`, have 8 MB. Bumping the io_pool stack doesn't fix the crash.
7. The standalone Python process (no imgui-bundle, no render loop) running the same adapter call from a ThreadPoolExecutor with default 1MB stack works fine for all 3 MOCK_MODE values.
## What we don't know yet
- **Whether the main thread is actually the one whose stack overflows** (vs. a thread we haven't yet identified — e.g., a HelloImGui-internal thread, or a thread created by imgui-bundle). To verify, I'd need to attach a debugger or add `SetUnhandledExceptionFilter` logging in the subprocess to dump the crashing thread's TEB.
- **What specific imgui-bundle code path causes the C stack to grow**. Without a debugger or `WER` crash dump, we can't see the C-side stack trace.
- **Whether the stack growth is linear (slow leak over many frames)** or **sudden (one specific draw call)**.
## Plausible root cause (next investigation step)
The most likely culprit is one of:
1. **`_render_message_panel` / `_render_response_panel` rendering path**: when `ai_status` becomes "error", the response panel starts rendering an error overlay. If the error overlay calls into imgui-bundle with a pathological layout (e.g., `add_rect` with a malformed argument list — the bug from `9fcf0517`!), imgui-bundle may recurse deeply into its C++ template metaprogramming for layout calc. **Even with the theme fix in 9fcf0517, the C++ stack usage per frame may have grown to the point where the next frame overflows the 1.94MB main thread stack.**
2. **A specific frame's draw call**: clicking `btn_gen_send` triggers `_do_generate` in a worker, which puts an event on the queue, which gets processed by the render loop on the next frame. The render loop renders the new state. That specific draw call has a deep C++ stack.
3. **External MCP server thread**: if any external MCP server is connected, its thread may have a small stack. But this would be caught by the io_pool stack bump, which we did.
## Recommended next steps (in order)
1. **Capture a Windows Error Reporting (WER) crash dump** from the subprocess. Run `sloppy.py` under a debugger (e.g., `cdb.exe -g -G -o sloppy.py --enable-test-hooks`) or use `procdump -ma -e 1 -f "" sloppy.py`. This will give us a `.dmp` file with full call stacks for ALL threads at the moment of crash.
2. **Add `SetUnhandledExceptionFilter` to the subprocess** that logs the crashing thread's TEB and stack to stderr before the process dies. The handler can be installed via `sitecustomize.py` so it doesn't require code changes to `sloppy.py`.
3. **Reduce the test's render load**: if the test workspace's layout file is 17KB and references 10 stale window names, that may be a major source of native stack usage per frame. Fix the stale layout (it has been stale for 7+ days per the WARNING in the log: "Run the 'Reset Layout' command from the Command Palette").
4. **Bump the main thread's stack at the OS level**: This requires modifying the PE header of `python.exe` (via `editbin /STACK:8388608 python.exe` on Windows) or recompiling. Neither is in scope for a 1-track fix.
## The fix path forward
**Short-term (ship in next track, 1-2 hours):**
- Fix the stale `manualslop_layout.ini` (it references 10 deleted window names, causing imgui-bundle to do extra work each frame)
- Capture a WER dump to identify the actual C-side stack frame that overflows
- If the dump points to a specific render function, fix that function
**Medium-term (separate track, 1-2 days):**
- Bump `sloppy.py`'s main thread stack via `editbin` (Windows) or by setting `PYTHONSTACKSIZE` env var if available
- Migrate heavy AI calls to a subprocess (`multiprocessing.Process`) so the C stack is per-call, not per-thread
**Long-term (architectural):**
- Move the GUI's render loop off the main thread (or use imgui-bundle's offscreen rendering mode) so the main thread is a thin renderer
- Move all `subprocess.Popen` calls to dedicated subprocess worker pool
## Files in this report
- `docs/reports/THEME_BUG_ANALYSIS_send_result_to_send_20260616.md` (the prior theme fix report, restored in `8c6d9aa0`)
- `docs/reports/NEGATIVE_FLOWS_INVESTIGATION_20260617.md` (the previous investigation — partially superseded)
- `docs/reports/NEGATIVE_FLOWS_INVESTIGATION_20260617_REFINED.md` (this file)
- `scripts/tier2/artifacts/send_result_to_send_20260616/diag_diag_stacks_init.py` (sitecustomize that sets 8MB stack + reports main thread stack size)
- `logs/sloppy_diag_stk_20260617_*.log` (log showing "Main thread stack: 1.94 MB" then crash)