diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index bb3cd02..ba4cf19 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -82,7 +82,7 @@ jobs: ;; 5) # HVAC supply sim smoke tests + hvac_validation + bar_building + concurrent regression - FILES="tests/test_hvac_supply_sim.py tests/test_hvac_validation.py tests/test_bar_building.py tests/test_concurrent_tools.py" + FILES="tests/test_hvac_supply_sim.py tests/test_hvac_validation.py tests/test_bar_building.py tests/test_concurrent_tools.py tests/test_stdout_logger_silence.py" EXTRA_ENV="" ;; esac diff --git a/CLAUDE.md b/CLAUDE.md index 7294830..8d6ccd6 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -36,11 +36,12 @@ Always use openstudio-mcp tools for BEM tasks: - Key modules: `model_manager.py` (load/get/save/clear model), `osm_helpers.py` (fetch_object, optional_name, list_all_as_dicts), `skills/__init__.py` (auto-discovers all skills) ## Stdout Suppression -Two real classes of stdout pollution corrupt MCP JSON-RPC — both caught by one fd redirect at startup. -- `stdout_suppression.py::redirect_c_stdout_to_stderr()` — called once in `server.py::main()` before `mcp.run()`. Permanently dups fd 1 → stderr; Python `sys.stdout` gets a private fd to the real MCP client pipe. -- **Class A — SWIG memleak warnings** (interpreter shutdown): `"swig/python detected a memory leak of type 'boost::optional< ... > *'"`. PyPI `openstudio==3.11.0` wheel was built WITHOUT `SWIG_PYTHON_SILENT_MEMLEAK`. Upstream SWIG#2638 / OpenStudio#5421; fix #5422 applied to .deb only, not the wheel we run. -- **Class B — Polyhedron Logger** (during ops): `[utilities.Polyhedron] <0> ...` from `Space::volume()`/`Space::floorArea()` on imperfect geometry via OpenStudio `LOG(Warn, ...)`. Unfiled upstream. -- `cbe6399`-style claims that FourPipeBeam / `add_baseline_system` emit stdout do NOT reproduce — the per-call wrappers that commit added are no-ops now; fd redirect covers real sources. +Two real classes of stdout pollution corrupt MCP JSON-RPC — two-layer defense at startup in `server.py::main()` before `mcp.run()`. +- **Class A — SWIG memleak warnings** (interpreter shutdown): `"swig/python detected a memory leak of type 'boost::optional< ... > *'"`. PyPI `openstudio==3.11.0` wheel built WITHOUT `SWIG_PYTHON_SILENT_MEMLEAK`. Upstream SWIG#2638 / OpenStudio#5421; fix #5422 applied to .deb only, not the wheel (filed as NatLabRockies/OpenStudio#5608). +- **Class B — OpenStudio Logger Polyhedron/Space** (during ops): `[utilities.Polyhedron]` / `[openstudio.model.Space]` warnings on stdout from `Space::volume()`/`floorArea()` on imperfect geometry. Default `standardOutLogger` sink runs at Warn level → C stdout. +- `stdout_suppression.py::silence_openstudio_stdout_logger()` — primary fix for Class B. Calls `openstudio.Logger.instance().standardOutLogger().setLogLevel(openstudio.Fatal)`. Uses intended Logger API, no fd manipulation. +- `stdout_suppression.py::redirect_c_stdout_to_stderr()` — backstop for Class A + unknowns. Permanently dups fd 1 → stderr; Python `sys.stdout` gets a private fd to the real MCP client pipe. +- `cbe6399`-style claims that FourPipeBeam / `add_baseline_system` emit stdout do NOT reproduce — per-call wrappers are no-ops now. - `suppress_openstudio_warnings()` retained as no-op for import compat - No action needed for new skills diff --git a/mcp_server/server.py b/mcp_server/server.py index 77941a0..290156f 100644 --- a/mcp_server/server.py +++ b/mcp_server/server.py @@ -4,7 +4,10 @@ from mcp_server.config import ENABLE_CODE_MODE from mcp_server.skills import register_all_skills -from mcp_server.stdout_suppression import redirect_c_stdout_to_stderr +from mcp_server.stdout_suppression import ( + redirect_c_stdout_to_stderr, + silence_openstudio_stdout_logger, +) mcp = FastMCP( "openstudio-mcp", @@ -53,6 +56,7 @@ def main(): + silence_openstudio_stdout_logger() redirect_c_stdout_to_stderr() mcp.run() diff --git a/mcp_server/stdout_suppression.py b/mcp_server/stdout_suppression.py index a6af381..c84bfd8 100644 --- a/mcp_server/stdout_suppression.py +++ b/mcp_server/stdout_suppression.py @@ -1,26 +1,29 @@ -"""Redirect C-level stdout to stderr to protect MCP JSON-RPC protocol. - -Two real sources of stdout pollution on our runtime (openstudio PyPI wheel -3.11.0) that would corrupt the JSON-RPC stream: - -1. SWIG memleak warnings at interpreter shutdown — - "swig/python detected a memory leak of type 'boost::optional< ... > *'" - Fires for boost::optional, boost::optional, etc. The - PyPI wheel was built WITHOUT SWIG_PYTHON_SILENT_MEMLEAK. Root cause is - SWIG#2638 / NatLabRockies/OpenStudio#5421; fix #5422 was applied to the - .deb build only, not the wheel we actually run. - -2. OpenStudio Logger output during Space::volume() / Space::floorArea() on - models with imperfect geometry — - "[utilities.Polyhedron] <0> Polyhedron is not enclosed in original - testing. Trying to add missing colinear points." - Source: LOG(Warn, ...) in OpenStudio utilities/Polyhedron. Unfiled - upstream as of 2026-04-11. - -Strategy: at process startup, permanently redirect fd 1 to stderr so ALL -C-level and logger writes go there harmlessly. Then replace Python's -sys.stdout with a wrapper around the saved original fd so FastMCP's stdio -transport still writes JSON-RPC to the real client pipe. +"""Keep stdout clean for MCP JSON-RPC on the openstudio PyPI wheel. + +Two real sources of stdout pollution on our runtime corrupt the JSON-RPC +stream. Two-layer defense at startup: + +Class A — SWIG memleak warnings at interpreter shutdown — + "swig/python detected a memory leak of type 'boost::optional< ... > *'" + Fires for boost::optional, boost::optional, etc. The PyPI + `openstudio==3.11.0` wheel was built WITHOUT SWIG_PYTHON_SILENT_MEMLEAK + (root cause SWIG#2638; OpenStudio#5421 was "fixed" by #5422 for .deb only, + wheel build missed it — filed as NatLabRockies/OpenStudio#5608). + Caught by `redirect_c_stdout_to_stderr` (fd-level backstop). + +Class B — OpenStudio Logger output during Space::volume() / floorArea() — + "[utilities.Polyhedron] <0> Polyhedron is not enclosed in original + testing. Trying to add missing colinear points." + "[openstudio.model.Space] <0> Object of type 'OS:Space' and named + '...' is not enclosed, there are N edges that aren't used..." + Source: the default `standardOutLogger` sink runs at Warn level and + writes to C stdout. Silenced via the intended Logger API in + `silence_openstudio_stdout_logger()`. + +Call order in server.py::main(): + 1. silence_openstudio_stdout_logger() # primary fix for Class B + 2. redirect_c_stdout_to_stderr() # backstop for Class A + unknowns + 3. mcp.run() Done once — no per-call suppression, no races, no missed callsites. """ @@ -33,10 +36,24 @@ import sys +def silence_openstudio_stdout_logger(): + """Set OpenStudio's standardOutLogger to Fatal level. + + Primary defense for Class B (Polyhedron/Space Logger warnings). + Uses the intended OpenStudio Logger API — no fd manipulation. + Call at process startup before any SDK operations. + """ + import openstudio + openstudio.Logger.instance().standardOutLogger().setLogLevel(openstudio.Fatal) + + def redirect_c_stdout_to_stderr(): """Permanently redirect C-level stdout (fd 1) to stderr. - Must be called before FastMCP's stdio_server() captures sys.stdout. + Belt-and-suspenders backstop for anything the Logger config doesn't + catch (SWIG memleak fprintfs under odd fd states, future unknown C + stdout writes). Must be called before FastMCP's stdio_server() + captures sys.stdout. After this call: - C code (printf, SWIG, OpenStudio internals) -> fd 1 -> stderr - Python sys.stdout -> saved fd -> real MCP client pipe @@ -50,9 +67,12 @@ def redirect_c_stdout_to_stderr(): # Point fd 1 at stderr — all future C-level printf goes here os.dup2(stderr_fd, stdout_fd) - # Build a new Python stdout that writes to the saved fd. - # Line buffering so each JSON-RPC message flushes immediately. - binary = io.open(saved_fd, "wb", closefd=True) + # Build a new Python stdout that writes to the saved fd. This file must + # outlive the function — it becomes sys.stdout for the rest of the + # process, so a context manager would close it prematurely. + # PTH123: Path.open() takes a path, not an fd — builtin open is correct here. + # SIM115: this file intentionally outlives the function. + binary = open(saved_fd, "wb", closefd=True) # noqa: SIM115, PTH123 text = io.TextIOWrapper(binary, encoding="utf-8", line_buffering=True) sys.stdout = text @@ -67,10 +87,8 @@ def suppress_openstudio_warnings(): def _redirect_stdout_to_stderr_at_exit(): """Safety net: ensure fd 1 points to stderr during interpreter shutdown.""" - try: + with contextlib.suppress(Exception): os.dup2(2, 1) - except Exception: - pass atexit.register(_redirect_stdout_to_stderr_at_exit) diff --git a/tests/test_stdout_logger_silence.py b/tests/test_stdout_logger_silence.py new file mode 100644 index 0000000..99aff0c --- /dev/null +++ b/tests/test_stdout_logger_silence.py @@ -0,0 +1,133 @@ +"""Verify silence_openstudio_stdout_logger keeps Polyhedron/Space warnings off fd 1.""" + +import os +import sys +import tempfile + +import pytest + + +@pytest.mark.integration +def test_silence_openstudio_stdout_logger_sets_fatal_level(): + # Validates: silence_openstudio_stdout_logger raises standardOutLogger level to Fatal + import openstudio + + from mcp_server.stdout_suppression import silence_openstudio_stdout_logger + + silence_openstudio_stdout_logger() + level = openstudio.Logger.instance().standardOutLogger().logLevel() + assert level.is_initialized(), "standardOutLogger level must be set" + assert level.get() == openstudio.Fatal, ( + f"expected Fatal (2), got {level.get()} — Polyhedron warnings will still leak" + ) + + +@pytest.mark.integration +def test_polyhedron_warnings_do_not_reach_stdout_after_silence(): + # Regression: [utilities.Polyhedron] / [openstudio.model.Space] warnings were + # reaching C stdout during Space::volume() on non-enclosed geometry, corrupting + # MCP JSON-RPC. silence_openstudio_stdout_logger() is the primary fix. + import openstudio + + from mcp_server.stdout_suppression import silence_openstudio_stdout_logger + + silence_openstudio_stdout_logger() + + # Build a Space with non-enclosed geometry (5 of 6 cube faces — roof missing) + m = openstudio.model.Model() + space = openstudio.model.Space(m) + P = openstudio.Point3d + + def poly(*pts): + v = openstudio.Point3dVector() + for p in pts: + v.append(p) + return v + + floor = openstudio.model.Surface( + poly(P(0, 0, 0), P(1, 0, 0), P(1, 1, 0), P(0, 1, 0)), m, + ) + floor.setSpace(space) + for verts in [ + poly(P(0, 0, 0), P(1, 0, 0), P(1, 0, 1), P(0, 0, 1)), + poly(P(1, 0, 0), P(1, 1, 0), P(1, 1, 1), P(1, 0, 1)), + poly(P(1, 1, 0), P(0, 1, 0), P(0, 1, 1), P(1, 1, 1)), + poly(P(0, 1, 0), P(0, 0, 0), P(0, 0, 1), P(0, 1, 1)), + ]: + openstudio.model.Surface(verts, m).setSpace(space) + + # Capture fd 1 at OS level around the Polyhedron trigger + cap = tempfile.NamedTemporaryFile(mode="r+", delete=False) + saved_fd1 = os.dup(1) + os.dup2(cap.fileno(), 1) + try: + _ = space.volume() + _ = space.floorArea() + finally: + sys.stdout.flush() + os.dup2(saved_fd1, 1) + os.close(saved_fd1) + + cap.seek(0) + captured = cap.read() + + assert captured == "", ( + f"expected clean stdout after silence_openstudio_stdout_logger, " + f"but captured {len(captured)} bytes: {captured[:300]!r}" + ) + + +@pytest.mark.integration +def test_without_silence_polyhedron_still_prints_to_stdout(): + # Validates: the bug exists — without our fix, Polyhedron Logger goes to fd 1. + # This test resets the level to Warn and confirms the pollution returns, + # so the previous test can't pass trivially by silencing something else. + import openstudio + + # Reset to default Warn level + openstudio.Logger.instance().standardOutLogger().setLogLevel(openstudio.Warn) + level = openstudio.Logger.instance().standardOutLogger().logLevel() + assert level.get() == openstudio.Warn + + m = openstudio.model.Model() + space = openstudio.model.Space(m) + P = openstudio.Point3d + + def poly(*pts): + v = openstudio.Point3dVector() + for p in pts: + v.append(p) + return v + + openstudio.model.Surface( + poly(P(0, 0, 0), P(1, 0, 0), P(1, 1, 0), P(0, 1, 0)), m, + ).setSpace(space) + for verts in [ + poly(P(0, 0, 0), P(1, 0, 0), P(1, 0, 1), P(0, 0, 1)), + poly(P(1, 0, 0), P(1, 1, 0), P(1, 1, 1), P(1, 0, 1)), + poly(P(1, 1, 0), P(0, 1, 0), P(0, 1, 1), P(1, 1, 1)), + poly(P(0, 1, 0), P(0, 0, 0), P(0, 0, 1), P(0, 1, 1)), + ]: + openstudio.model.Surface(verts, m).setSpace(space) + + cap = tempfile.NamedTemporaryFile(mode="r+", delete=False) + saved_fd1 = os.dup(1) + os.dup2(cap.fileno(), 1) + try: + _ = space.volume() + finally: + sys.stdout.flush() + os.dup2(saved_fd1, 1) + os.close(saved_fd1) + + cap.seek(0) + captured = cap.read() + + # Restore silence so remaining tests in the file see Fatal + openstudio.Logger.instance().standardOutLogger().setLogLevel(openstudio.Fatal) + + assert "Polyhedron" in captured or "Space" in captured, ( + f"expected Polyhedron/Space Logger output on stdout at Warn level, " + f"got {captured!r} — if this fails, openstudio upstream may have " + f"changed the default sink and our fix can be simplified" + )