Skip to content

fix: drain native stderr pipe concurrently to unblock EP compilation - #1223

Merged
KayMKM merged 1 commit into
mainfrom
yuesu/fix-stderr-deadlock-and-vaip-cache
Jul 27, 2026
Merged

fix: drain native stderr pipe concurrently to unblock EP compilation#1223
KayMKM merged 1 commit into
mainfrom
yuesu/fix-stderr-deadlock-and-vaip-cache

Conversation

@KayMKM

@KayMKM KayMKM commented Jul 27, 2026

Copy link
Copy Markdown
Contributor

Why

capture_native_stderr redirected fd 2 into an OS pipe but only drained it
after the wrapped block returned. A native EP that wrote more than the pipe
buffer holds (~64 KB on Windows) blocked in write() and never returned, so the
wrapped block never completed and the drain never ran.

VitisAI model compilation emits several hundred lines of compiler output on
native stderr and reliably filled the buffer, stalling session creation
indefinitely.

Measured on an AMD Ryzen AI 9 HX 370 (VitisAI EP 1.8.72.0, EP cache emptied
before each run):

Scenario Result
winml perf ... --ep vitisai --precision fp16 ran 17m52s without completing; no compile artifacts written for the last 14m45s
Same model + EP, session created outside the context manager completed in 185s
Same model + EP, session created inside capture_native_stderr stalled at the same compilation stage

The last variant isolates the context manager as the cause: same model, same EP,
same session options, same empty cache.

What changed

  • capture_native_stderr drains concurrently. A daemon reader thread starts
    before the yield, so the pipe is emptied while the wrapped block runs and the
    buffer never fills. Restoring fd 2 drops the last write-end reference, which
    signals EOF to the reader; it is then joined and the captured lines are
    re-emitted through logging exactly as before. No change to the public
    behaviour (capture, ANSI stripping, [ORT] prefix).

  • The eval harness now clears the VitisAI EP compilation cache. It lives
    outside the user profile (C:\temp\<user>\vaip\.cache), so clearing only the
    HuggingFace and WinML caches left compiled NPU artifacts behind. AMD documents
    that these directories must not be reused across VitisAI EP or NPU driver
    versions, and a stale entry also lets a run load a previously compiled model
    instead of exercising the compile path under test.

  • Regression coverage. test_no_deadlock_on_large_output writes ~720 KB
    inside the context manager under a 30s timeout, so a reintroduced deadlock
    fails instead of hanging. TestClearDiskCaches covers the new cache directory
    and the None case on non-Windows.

Validation

  • pytest tests/unit/utils/test_native_stderr.py — 8 passed, 1 skipped
  • pytest tests/unit/eval/test_run_eval_script.py — 111 passed
  • ruff check clean on all touched files
  • winml perf -m facebook/convnext-tiny-224 --device npu --ep vitisai --precision fp16
    completes in 3m23s (was: no completion after 17m52s)
  • run_eval.py --hf-model facebook/convnext-tiny-224 --device npu --ep vitisai
    reports [PASS] 172.4s, perf pass 1/1 (was: [FAIL (TIMEOUT)] 601.9s)

capture_native_stderr redirected fd 2 into an OS pipe but only drained it
after the wrapped block returned. A native EP that wrote more than the pipe
buffer holds (~64 KB on Windows) blocked in write() and never returned, so
the block never completed and the drain never ran.

VitisAI model compilation emits several hundred lines of compiler output on
native stderr and reliably filled the buffer, stalling session creation
indefinitely: winml perf -m facebook/convnext-tiny-224 --device npu
--ep vitisai --precision fp16 ran for 17m52s without completing, with no
compile artifacts written for the last 14m45s, while the same model and EP
compiled in 185s through a session created outside the context manager.

Start a daemon reader thread before the yield so the pipe is drained while
the wrapped block runs and the buffer never fills. Restoring fd 2 drops the
last write-end reference, which signals EOF to the reader; it is then joined
and the captured lines are re-emitted through logging as before.

Also clear the VitisAI EP compilation cache in the eval harness. It lives
outside the user profile (C:\temp\<user>\vaip\.cache), so clearing only the
HuggingFace and WinML caches left compiled NPU artifacts behind. AMD
documents that these directories must not be reused across VitisAI EP or NPU
driver versions, and a stale entry also lets a run load a previously
compiled model instead of exercising the compile path under test.

After the fix the same perf run completes in 3m23s, and the eval harness
reports [PASS] 172.4s (1/1) for the vitisai_npu fp16 job that previously
timed out.
@KayMKM
KayMKM requested a review from a team as a code owner July 27, 2026 08:31
@KayMKM
KayMKM merged commit 57c2cdf into main Jul 27, 2026
9 checks passed
@KayMKM
KayMKM deleted the yuesu/fix-stderr-deadlock-and-vaip-cache branch July 27, 2026 08:38
KayMKM added a commit that referenced this pull request Jul 31, 2026
## Summary
- replace the pipe used by native warning suppression with a file-backed
temporary spool
- filter and replay preserved native diagnostics only after restoring
stderr
- retain fail-open behavior, Windows handle restoration, warning
filtering, and bounded memory usage

## Root cause
The warning filter introduced in #1246 redirected native stderr to a
pipe. VitisAI can hang inside `ort.InferenceSession` when its compiler
sees that pipe handle. The reader was draining correctly, so this was
not the full-buffer deadlock fixed by #1223; changing the reader to
defer replay still hung, which isolated the pipe handle itself as the
trigger.

A temporary file preserves warning filtering without pipe semantics or a
finite producer buffer. With an empty VAIP cache and no VitisAI-specific
bypass, `facebook/convnext-tiny-224` completed on VitisAI NPU in 144.1
seconds. Disabling warning filtering entirely completed the same
workload in 145.1 seconds.

## Validation
- `uv run --no-sync pytest tests/unit/utils/test_native_stderr.py
tests/unit/commands/test_perf_cli.py -q --basetemp
temp/pytest_tmp/native-warning-file-backed-final` (143 passed, 1
platform skip)
- `uvx ruff check src/winml/modelkit/utils/native_stderr.py
tests/unit/utils/test_native_stderr.py
src/winml/modelkit/commands/perf.py
tests/unit/commands/test_perf_cli.py`
- cold-cache VitisAI NPU perf with warning filtering enabled: PASS in
144.1s
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants