From 364f0452fc5a88ac739c5bea9f9cf909cf4172bc Mon Sep 17 00:00:00 2001 From: modusensus Date: Sun, 20 Sep 2026 12:56:45 +0800 Subject: [PATCH 1/4] =?UTF-8?q?test:=20=E7=AD=89=E5=BE=85=E6=94=B9?= =?UTF-8?q?=E4=B8=BA=E5=B8=A6=E6=88=AA=E6=AD=A2=E6=97=B6=E9=97=B4=E7=9A=84?= =?UTF-8?q?=E8=B0=93=E8=AF=8D=EF=BC=8C=E8=B7=A8=E6=96=87=E4=BB=B6=E5=85=B1?= =?UTF-8?q?=E7=94=A8=20tests/=5Fwaits.py?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 固定秒数的 sleep 断言的是“这台机器够快”而不是被测行为:慢机器上它随机红,快机器上它 永远绿——两种结果都不回答“被测代码对不对”。 - 新增 tests/_waits.py:wait_for / wait_for_values / join_thread。为什么跨文件共用一个 实现:每处自己发明“等一会儿”时,余量都会被写成某个具体秒数(本仓曾同时存在 0.05 / 0.15 / 0.3),而谁也说不清哪个是真约束。 - test_health.py 用它替换本地实现;“停下来”改用 join 证明线程已死。 - test_retry.py 去掉“先睡 0.3 秒再 join”——sleep 的 join 前缀什么也没保证,join 才是 这段真正要的等待,而且它顺带证明了驱动线程会自己退出。 - pyproject 里显式声明 tests/ 下的内部助手为 first-party,否则 ruff 会把它们归到 第三方段。 🤖 Generated with Codebuff Co-Authored-By: Codebuff --- pyproject.toml | 5 ++++ tests/_waits.py | 63 ++++++++++++++++++++++++++++++++++++++++++++ tests/test_health.py | 38 +++++--------------------- tests/test_retry.py | 9 ++++--- 4 files changed, 80 insertions(+), 35 deletions(-) create mode 100644 tests/_waits.py diff --git a/pyproject.toml b/pyproject.toml index b17e3e2..35fbd33 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -93,6 +93,11 @@ ignore = [ # typer 要求 Option/Argument 作为参数默认值出现。 "ponte/main.py" = ["B008"] +[tool.ruff.lint.isort] +# tests/ 下以单下划线开头的内部助手("等待"与"负载注入")是本仓库的代码,不是第三方 +# 包。不声明的话 ruff 会把它们归到第三方段,于是 import 分组传达的信息是错的。 +known-first-party = ["ponte", "_injection", "_waits"] + [tool.mypy] python_version = "3.11" files = ["ponte"] diff --git a/tests/_waits.py b/tests/_waits.py new file mode 100644 index 0000000..541a11e --- /dev/null +++ b/tests/_waits.py @@ -0,0 +1,63 @@ +"""共用的确定性等待助手。 + +固定秒数的 ``sleep`` 断言的是"这台机器够快",而不是被测行为:慢 runner 上它会随机 +变红(main 上真的红过一次),快机器上它永远绿——两种结果都不回答"被测代码对不对"。 +所以这里只做一件事:**等谓词成立,带截止时间**;等不到即失败,并带上现场。 + +为什么值得跨文件共用一个实现:每处自己发明"等一会儿"时,余量都会被写成某个具体秒数 +(这个仓库里曾同时存在 0.05 / 0.15 / 0.3),而谁也说不清哪个是真约束、哪个只是习惯。 +共用之后,唯一需要商量的是截止时间本身——它才是这些等待表达的约束。 +""" + +from __future__ import annotations + +import threading +import time +from collections.abc import Callable + +#: 轮询间隔。足够小以便及时看到副作用;又不为空转——空转要吃 GIL,会把等待者自己 +#: 变成它本想模拟的那种负载,于是测出的是噪声而不是行为。 +_POLL = 0.01 + +#: 默认截止时间。等待的**上界**才是它表达的约束:机器多慢都应该在这之内到达。 +DEFAULT_TIMEOUT = 5.0 + + +def wait_for( + predicate: Callable[[], bool], + describe: Callable[[], str], + timeout: float = DEFAULT_TIMEOUT, +) -> None: + """等到 *predicate* 成立,然后断言它成立。 + + ``describe`` 是个函数而不是字符串:失败信息必须在**等过之后**才取,否则记录的是 + 等待开始前那一刻的状态,只说明"当时还没到",对定位毫无帮助。 + """ + deadline = time.monotonic() + timeout + while not predicate() and time.monotonic() < deadline: + time.sleep(_POLL) + assert predicate(), describe() + + +def wait_for_values(values: list, n: int, timeout: float = DEFAULT_TIMEOUT) -> None: + """等到 ``values`` 至少有 ``n`` 个元素。""" + wait_for( + lambda: len(values) >= n, + lambda: f"captured only {len(values)} values, need {n}", + timeout, + ) + + +def join_thread( + thread: threading.Thread, + timeout: float = DEFAULT_TIMEOUT, + what: str | None = None, +) -> None: + """等 *thread* 结束,并断言它真的结束了。 + + "停下来"这类断言该用 join 证明线程已死,而不是"睡一会儿看计数没变"——后者在慢 + 机器上会通过(还没来得及变),在快机器上也可能通过(正好没变),两头都不作数。 + 线程结束后计数不再变化,之后的遍历才是确定性的。 + """ + thread.join(timeout=timeout) + assert not thread.is_alive(), f"{what or thread.name} still running after {timeout:g}s" diff --git a/tests/test_health.py b/tests/test_health.py index 9ae03d4..503e272 100644 --- a/tests/test_health.py +++ b/tests/test_health.py @@ -4,10 +4,10 @@ import threading import time -from collections.abc import Callable import pytest +from _waits import join_thread, wait_for, wait_for_values from ponte.config import HealthConfig from ponte.core import ProbeError from ponte.health import HealthChecker, HealthStatus @@ -175,12 +175,11 @@ def test_run_loop_stops_cleanly() -> None: monitor = next((t for t in threading.enumerate() if t not in before_threads), None) assert monitor is not None, "run_loop 没有起后台线程" - _wait_for_values(seen, 3) + wait_for_values(seen, 3) checks_at_stop = len(seen) stop.set() - monitor.join(timeout=5) - assert not monitor.is_alive(), "设置停止事件后循环没有退出" + join_thread(monitor, what="健康监控线程", timeout=5) # 已经进入 check() 的那一轮仍会回调一次(实现只保证在 wait 之前查一次事件), # 再多就说明停止没生效。线程已 join,计数此后不会再变,所以这是确定性的。 late = len(seen) - checks_at_stop @@ -196,7 +195,7 @@ def bad_cb(_st: HealthStatus) -> None: raise ValueError("cb boom") stop = hc.run_loop(interval=0.02, callback=bad_cb) - _wait_for( + wait_for( lambda: isinstance(hc.last_callback_error, ValueError), lambda: f"回调异常没被记录:{hc.last_callback_error!r}", ) @@ -298,31 +297,6 @@ def test_backoff_interval_formula() -> None: assert HealthChecker._backoff_interval(60.0, 10, 300.0) == 300.0 -def _wait_for( - predicate: Callable[[], bool], - describe: Callable[[], str], - timeout: float = 5.0, -) -> None: - """Wait for *predicate* on a deadline, instead of napping a fixed time. - - 固定秒数的 ``sleep`` 断言的是"这台机器够快",而不是被测行为。``describe`` - 是个函数:失败信息要在**等过之后**才取,否则它记的是等待前那一刻的状态。 - """ - deadline = time.time() + timeout - while not predicate() and time.time() < deadline: - time.sleep(0.01) - assert predicate(), describe() - - -def _wait_for_values(values: list, n: int, timeout: float = 5.0) -> None: - """Busy-wait until ``values`` has at least ``n`` entries.""" - _wait_for( - lambda: len(values) >= n, - lambda: f"captured only {len(values)} values, need {n}", - timeout, - ) - - def _fake_wait_recorder( monkeypatch, waits: list[float], released: threading.Event ) -> None: @@ -366,7 +340,7 @@ def test_run_loop_backoff_after_failures(monkeypatch) -> None: _fake_wait_recorder(monkeypatch, waits, released) hc.run_loop(interval=1.0) - _wait_for_values(waits, 6) + wait_for_values(waits, 6) released.set() _stop_health_thread() @@ -412,7 +386,7 @@ def check_remote_ports(self, **kw) -> dict[int, bool]: _fake_wait_recorder(monkeypatch, waits, released) hc.run_loop(interval=1.0) - _wait_for_values(waits, 7) + wait_for_values(waits, 7) released.set() _stop_health_thread() diff --git a/tests/test_retry.py b/tests/test_retry.py index f378b41..fbd1282 100644 --- a/tests/test_retry.py +++ b/tests/test_retry.py @@ -10,6 +10,7 @@ import threading import time +from _waits import join_thread from ponte.config import RetryConfig from ponte.retry import RetryEvent, RetryRunner @@ -59,10 +60,12 @@ def driver() -> None: if ev.type == RetryEvent.RETRYING: runner.stop() - t = threading.Thread(target=driver) + t = threading.Thread(target=driver, name="retry-driver") t.start() - time.sleep(0.3) - t.join() + # 这里曾经先 ``time.sleep(0.3)`` 再 ``join()``。那个 0.3 既不是约束也不是事实, + # 只是"希望此时它已经跑完了";慢 runner 上它什么也没保证。join 才是这段真正 + # 要的等待,而且它同时证明了驱动线程会自己退出(不会把套件挂住)。 + join_thread(t, what="重试驱动线程", timeout=10) assert events[0][0] == RetryEvent.CONNECTING, events idx = [e[0] for e in events] From da8ed653f67fabb7540aebc3dced9f68cb536102 Mon Sep 17 00:00:00 2001 From: modusensus Date: Sun, 20 Sep 2026 12:56:57 +0800 Subject: [PATCH 2/4] =?UTF-8?q?fix(core):=20stderr=20drain=20=E7=BA=BF?= =?UTF-8?q?=E7=A8=8B=E8=AF=BB=E7=9A=84=E6=98=AF=E4=BA=A4=E7=BB=99=E5=AE=83?= =?UTF-8?q?=E7=9A=84=E8=BF=9B=E7=A8=8B=EF=BC=8C=E8=80=8C=E4=B8=8D=E6=98=AF?= =?UTF-8?q?=E5=85=B1=E4=BA=AB=E5=AD=97=E6=AE=B5?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit connect() 把 SSH 子进程的 stderr 交给守护线程去读(否则 stderr=PIPE 的缓冲区一旦填满 就会把 SSH 别住),而那个线程是在**被调度之后**才从 self.process 取进程引用的;同时 connect() 在会话结束时(finally)就把该字段清成了 None。于是线程只要晚一点跑到第一行 ——忙机器上的常态——它拿到的就是 None,直接返回,什么都没读:它存在的理由恰好被它自己 绕过了。改成创建线程时把进程交给它。 这个竞态不是读代码发现的:它是新的“线程启动延迟”注入逼出来的(本机空闲时永远绿,注入 延迟 0.15s 后每次都红)。所以同时加上一条不依赖注入的契约测试:self.process 已经是 None 时,交给该线程的进程照样得被读完。 🤖 Generated with Codebuff Co-Authored-By: Codebuff --- CHANGELOG.md | 10 ++++++++++ ponte/core.py | 21 +++++++++++++++++---- tests/test_core.py | 36 +++++++++++++++++++++++++++++++++--- 3 files changed, 60 insertions(+), 7 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4cab226..bc61168 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,16 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed +- **A busy machine could leave the SSH session's stderr unread.** `connect()` + hands the child's stderr to a daemon thread so the pipe can never fill up and + server-side disconnects are logged while they happen. That thread read the + process from `self.process` *after* it was scheduled, while `connect()` clears + that attribute the moment the session ends — so a thread that reached its + first line late found `None` and drained nothing at all, leaving unread the + very pipe it exists to keep empty (once the buffer fills, SSH stalls). The + process is now handed to the thread when it is created. This was found by the + new scheduling injection, not by reading the code: it is a race whose window + is tiny on an idle machine and wide open on a loaded one. - **A failed health probe was reported as a dead port — and could kill a healthy tunnel.** The server-side probe is an SSH connection of its own, and when that connection failed (a reset, provider-side rate limiting, our own timeout kill) diff --git a/ponte/core.py b/ponte/core.py index e848011..6dda25e 100644 --- a/ponte/core.py +++ b/ponte/core.py @@ -212,7 +212,7 @@ def connect(self) -> int: """ args = self.build_args() logger.info("Launching: %s", " ".join(args)) - self.process = subprocess.Popen( + proc = subprocess.Popen( args, stdout=subprocess.DEVNULL, stderr=subprocess.PIPE, @@ -228,12 +228,22 @@ def connect(self) -> int: close_fds=True, creationflags=creation_flags(), ) + self.process = proc self._connected_at = time.monotonic() # Drain stderr on a daemon thread: the pipe can never fill up (which # would stall SSH), and disconnect reasons are logged in real time # instead of only after the session ends. + # + # The process is handed to the thread rather than read from + # ``self.process`` inside it. That attribute is cleared as soon as the + # session ends (``finally`` below), and no amount of being fast prevents + # the *other* direction: a thread that is scheduled late starts after the + # clear, finds ``None``, and silently drains nothing — a busy machine + # turns this into "the pipe nobody reads", which is the failure this + # thread exists to prevent. threading.Thread( target=self._drain_stderr, + args=(proc,), name="ponte-ssh-stderr", daemon=True, ).start() @@ -247,15 +257,18 @@ def connect(self) -> int: finally: self.process = None - def _drain_stderr(self) -> None: - """Read the SSH child's stderr line by line until EOF. + def _drain_stderr(self, proc: subprocess.Popen | None) -> None: + """Read the stderr of *proc* line by line until EOF. Runs on a daemon thread for the lifetime of the session. Prevents the ``stderr=PIPE`` buffer from filling up and logs server-side disconnect reasons (e.g. ``Connection to host closed by remote host``) as they happen, so a dropped tunnel is diagnosable even after the fact. + + ``proc`` is a parameter, not ``self.process``: see ``connect()`` — the + session that owns this pipe must keep being drained even if this thread + only reaches its first line after ``connect()`` returned. """ - proc = self.process if proc is None or proc.stderr is None: return try: diff --git a/tests/test_core.py b/tests/test_core.py index ab91f26..f323813 100644 --- a/tests/test_core.py +++ b/tests/test_core.py @@ -9,10 +9,10 @@ import dataclasses import subprocess import sys -import time import pytest +from _waits import wait_for from ponte.config import ( JumpHop, Profile, @@ -416,8 +416,38 @@ def poll(self): tm = TunnelManager(_cfg()) with caplog.at_level("WARNING", logger="ponte.core"): tm.connect() - time.sleep(0.05) # give the stderr drain thread a moment to flush - assert "auth failed" in caplog.text + # 这里曾经是 ``time.sleep(0.05)`` "给 drain 线程一点时间"——那是在断言这台机器 + # 够快(慢 runner 上 drain 线程就是排不到,测试随机红)。能等的只有"日志记录 + # 出现"这个事实本身,所以等它,等不到 5 秒才算失败。 + wait_for( + lambda: any("auth failed" in r.getMessage() for r in caplog.records), + lambda: f"drain 线程没有记录 stderr:" + f"{[r.getMessage() for r in caplog.records]!r}", + ) + assert "SSH stderr: auth failed" in caplog.text + + +def test_drain_stderr_reads_the_process_it_was_handed(caplog) -> None: + """drain 线程要读的进程必须随线程一起传进去,而不是事后读 ``self.process``。 + + ``connect()`` 的 ``finally`` 会把 ``self.process`` 清成 ``None``。线程被调度得 + 晚一点(慢 runner 上很常见)就会读到 ``None``,于是整条 stderr 没人读——而 + ``stderr=PIPE`` 的缓冲区填满、把 SSH 别住,正是这条线程存在的理由。 + + 这里直接钉住那个契约:即使 ``self.process`` 已经是 ``None``,交给这条线程的 + 进程照样得被读完。上面那条测试只能靠**调度很晚**才能发现这个竞态(所以它需要 + 时序注入),这条不需要。 + """ + + class _Proc: + def __init__(self) -> None: + self.stderr = iter((b"Connection to host closed by remote host\n",)) + + tm = TunnelManager(_cfg()) + tm.process = None # 就是 connect() 返回之后的状态 + with caplog.at_level("WARNING", logger="ponte.core"): + tm._drain_stderr(_Proc()) + assert "SSH stderr: Connection to host closed by remote host" in caplog.text def test_connect_records_last_session_duration(monkeypatch) -> None: From 11eb2ce8d22e84fc6335bed1696d6ca480eee999 Mon Sep 17 00:00:00 2001 From: modusensus Date: Sun, 20 Sep 2026 12:57:11 +0800 Subject: [PATCH 3/4] =?UTF-8?q?test(ci):=20=E6=97=B6=E5=BA=8F=E5=AE=88?= =?UTF-8?q?=E5=8D=AB=E5=8A=A0=E2=80=9C=E7=BA=BF=E7=A8=8B=E8=A2=AB=E8=B0=83?= =?UTF-8?q?=E5=BA=A6=E5=BE=97=E6=99=9A=E2=80=9D=E8=BF=99=E6=9D=A1=E8=BD=B4?= =?UTF-8?q?=EF=BC=8C=E5=B9=B6=E8=A1=A5=E4=B8=8A=E8=A2=AB=E6=BC=8F=E6=8E=89?= =?UTF-8?q?=E7=9A=84=E7=8E=AF=E5=A2=83=E7=BB=B4=E5=BA=A6?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit **第二条轴(PONTE_TEST_THREAD_START_DELAY)。** 原来的注入只把工作线程的 sleep/wait 拉长,而“线程已经 start() 却迟迟跑不到第一行”它够不到:还没开始执行的线程没有任何等待 可以被拉长。就这一条缝隙里藏着真 bug——它让 TunnelManager.connect 的 stderr drain 竞态 从“偶尔”变成“每次”(见上一个提交),也复现了当初把 main 弄红的那类断言。 **被否决的第三条轴,连同实测数字。** “工作线程缺 CPU”试过了:一个 100% 忙等的 Python 线程让 pytest 的收集阶段从 0.43s 变成 30s(两个线程 68s),而且它**抓不到**上面那条 竞态——竞争者的 sleep 会释放 GIL,被反调度的线程照样能在 50ms 的 nap 里跑起来。GIL 争抢加的是“每次重新获取最多 5ms 的延迟”,不是吞吐;那是前两条轴已经能做的事,且是免费 和确定性的。数字写在 tests/_injection.py 里,免得下一个人重新掏这笔钱。 **守卫的自检从“测量机制”升级成“证明它能把绿变红”。** 子进程里跑一条故意依赖时序的 探针:注入开着时必须失败、关掉时必须通过。只验前一半是不够的——一个把所有东西都弄红的 坏注入同样满足它。 **CI 的三个新维度**(都在同一批里,因为第一条腿已经证明了“环境差异”值得单独跑): - Python 3.13 / 3.14 进矩阵:版本差异不是装饰,v4-mapped 回环判定就在 3.11 与 3.12 之间 变过,而那直接决定这个工具要不要令牌。 - 新腿:C locale(非 UTF-8 stdio,需 PYTHONCOERCECLOCALE=0 才不是空跑)+ 半时区偏移 (UTC+5:30)+ 弃用告警当错误。 - 顺带在本地就把这条腿该发现的东西找到了:我的新自检在 ASCII stderr 上写不出中文报错, 于是它自己成了它想找的那类环境依赖——探针的文本已改成 ASCII。 🤖 Generated with Codebuff Co-Authored-By: Codebuff --- .github/workflows/ci.yml | 52 ++++++++++- CHANGELOG.md | 10 +++ CONTRIBUTING.md | 37 +++++--- README.md | 32 ++++--- tests/_injection.py | 177 +++++++++++++++++++++++++++++++++++++ tests/conftest.py | 88 +++--------------- tests/test_timing_guard.py | 124 +++++++++++++++++++++++--- 7 files changed, 403 insertions(+), 117 deletions(-) create mode 100644 tests/_injection.py diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index e494646..bcfd543 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -37,7 +37,10 @@ jobs: fail-fast: false matrix: os: [ubuntu-latest, macos-latest, windows-latest] - python-version: ["3.11", "3.12"] + # 下限(3.11)与上限都测:本仓声明 >=3.11,而 3.13/3.14 上的解释器行为真的会 + # 变——v4-mapped 的 ``::ffff:127.0.0.1`` 在 3.11 上不被认作回环、3.12 上被 + # 认作回环,就是一个只在某个版本上才暴露的例子。 + python-version: ["3.11", "3.12", "3.13", "3.14"] steps: - uses: actions/checkout@v4 @@ -62,8 +65,12 @@ jobs: # 依赖时序的断言只会**随机**报红:main 上 Python 3.11 (macos-latest) 就因为 # "睡 0.3 秒后至少 3 次检查"拿到 2 而红过一次——不是产品代码错,而是断言考的是 - # "这台机器够快"。这条腿把那种机器搬进 CI:往工作线程注入延迟(见 - # tests/conftest.py),于是这类测试**当场**失败,而不是某天随机变红。 + # "这台机器够快"。这条腿把那种机器搬进 CI(见 tests/_injection.py),于是这类测试 + # **当场**失败,而不是某天随机变红。两条轴各自独立: + # - 工作线程自己的等待被拉长; + # - 线程被 start() 了但迟迟跑不到第一行(等待被拉长管不到这种——它没有任何等待 + # 可拉长)。这条轴真的抓到过东西:它让 TunnelManager.connect 里 stderr drain + # 线程的竞态(读已被清空的 self.process)从"偶尔"变成"每次"。 # # 只跑一个 OS/版本:它的价值在确定性,不在覆盖率——版本/平台差异由上面的矩阵负责。 timing: @@ -81,15 +88,52 @@ jobs: - name: Install project with dev deps run: python -m pip install --upgrade pip && pip install -e ".[dev]" - # 故意不加 `-q`:报告头里的那行横幅就是"守卫真的开着"的证据,下一行 grep 它。 + # 故意不加 `-q`:报告头里的那两行横幅就是"守卫真的开着"的证据,下面 grep 它们。 # 一条静默失效的注入会把这条腿变成空跑,而输出仍然是绿的。 - name: Run tests with injected latency env: PONTE_TEST_THREAD_DELAY: "0.15" + PONTE_TEST_THREAD_START_DELAY: "0.15" run: | set -o pipefail pytest 2>&1 | tee slow-runner.log grep -q "thread latency: +0.15s" slow-runner.log + grep -q "thread start delay: +0.15s" slow-runner.log + + # 一条腿覆盖三个"环境"维度(不是平台维度,平台由上面的矩阵负责)。合成一条是因为 + # 它们都是同一件事的不同侧面:**这台机器不是开发者那台**。出错时 traceback 会指出 + # 是哪个维度,所以合并的代价只是少一次归因,换来少两个 job。 + # + # - C locale + 非 UTF-8:CI 默认是 UTF-8,但真实服务器上 LANG 经常根本没设。 + # PYTHONCOERCECLOCALE=0 是必须的——没有它 Python 会把 C locale 自动"挽救"成 + # C.UTF-8(PEP 538),这条腿就变成空跑。ponte 的输出里有中文,所以这不是假想问题。 + # - 半时区偏移(UTC+5:30):按整小时做的本地时间算术在这里会错一个小时的一半。 + # - 弃用告警当错误:这个小工具要长期支持 3.11+,用过就废的 API 应该当场红, + # 而不是等某个版本把它删掉才红。 + env-edges: + name: Environment edges (C locale, half-hour TZ, deprecations) + runs-on: ubuntu-latest + + steps: + - uses: actions/checkout@v4 + + - name: Set up Python + uses: actions/setup-python@v5 + with: + python-version: "3.13" + + # pip 这一步在正常 locale 下跑:安装期的警告不是这条腿要考的东西。 + - name: Install project with dev deps + run: python -m pip install --upgrade pip && pip install -e ".[dev]" + + - name: Run tests in a non-UTF-8 half-hour timezone + env: + LC_ALL: C + LANG: C + PYTHONCOERCECLOCALE: "0" + PYTHONUTF8: "0" + TZ: Asia/Kolkata + run: pytest -W error::DeprecationWarning build: name: Build & verify wheel diff --git a/CHANGELOG.md b/CHANGELOG.md index bc61168..57b6f05 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -109,6 +109,16 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Changed +- **CI exercises two further environments and one further failure class.** The + test matrix now runs Python 3.13 and 3.14 as well — the runtime is not + decoration: `IPv4Address` handling of `::ffff:127.0.0.1` changed between 3.11 + and 3.12, and that difference decided whether this tool demanded an auth + token. One job runs the suite under a C locale (non-UTF-8 stdio) in a + half-hour timezone with deprecation warnings as errors. And the "slow runner" + job gained a second, independent axis: `PONTE_TEST_THREAD_START_DELAY` holds a + freshly started thread before its first line runs — a case stretching waits + cannot reach, because a thread that has not started executing performs no + waits to stretch. - **Every SSH path now builds its connection flags in one place.** The tunnel, the login test behind `ponte test` / the health loop / `doctor`, and the server-side port probe each assembled their own `-o`/`-i`/`-p` list, so a diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index ef94869..a88f4d7 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -33,18 +33,26 @@ python _smoke_test.py # zero-dependency smoke check Coverage has a `fail_under` threshold in `pyproject.toml`; don't let it drop. CI runs lint + types on Linux, the same test suite on Windows / Linux / macOS × -Python 3.11 / 3.12, and a `build` job that installs the wheel and runs +Python 3.11–3.14, a job that re-runs it under a C locale / half-hour timezone +with deprecations as errors, and a `build` job that installs the wheel and runs `ponte init`. Coverage is uploaded to Codecov. -One more job re-runs the suite with `PONTE_TEST_THREAD_DELAY=0.15`. That variable -makes `tests/conftest.py` inject latency into worker-thread sleeps and waits, so a +One more job re-runs the suite with two independent injections (`tests/_injection.py`): +`PONTE_TEST_THREAD_DELAY=0.15` stretches every worker-thread sleep and wait, and +`PONTE_TEST_THREAD_START_DELAY=0.15` holds a freshly started thread before it runs +its first line. The second one matters because it is unreachable by the first: a +thread that has not started executing yet has no waits to stretch. Either way, a test that only passes because the machine is fast fails there **every time** instead of flaking once in a while. Run it the same way before blaming a runner: ```bash -PONTE_TEST_THREAD_DELAY=0.15 pytest # 慢机器模拟(Git Bash / POSIX 语法) +PONTE_TEST_THREAD_DELAY=0.15 PONTE_TEST_THREAD_START_DELAY=0.15 pytest ``` +If you add an assertion that waits for something a background thread produces, wait +for a deadline (see `tests/_waits.py`) rather than for a fixed number of seconds; +the guard job is what turns the difference into a failure instead of a flake. + ## Project layout ``` @@ -157,19 +165,24 @@ python _smoke_test.py # 零依赖冒烟检查 ``` 覆盖率在 `pyproject.toml` 里有 `fail_under` 阈值,请勿让它回落。CI 会在 -Linux 上跑 lint + 类型检查,在 Windows / Linux / macOS × Python 3.11 / 3.12 -上跑同一套测试,另有 `build` 任务会安装 wheel 并执行 `ponte init`。覆盖率 -上报到 Codecov。 +Linux 上跑 lint + 类型检查,在 Windows / Linux / macOS × Python 3.11–3.14 +上跑同一套测试,另有一个任务在 C locale / 半时区偏移下、并把弃用告警当错误地跑一遍, +以及 `build` 任务会安装 wheel 并执行 `ponte init`。覆盖率上报到 Codecov。 -还有一个任务会用 `PONTE_TEST_THREAD_DELAY=0.15` 再跑一遍:这个变量让 -`tests/conftest.py` 往工作线程的 sleep/wait 里注入延迟,于是“只有机器够快才 -通过”的测试会**每次都**在那里失败,而不是偶发地红一次。怀疑是 runner 抽风之前, -先这样在本地跑一遍: +还有一个任务会用两个互相独立的注入(见 `tests/_injection.py`)再跑一遍: +`PONTE_TEST_THREAD_DELAY=0.15` 把工作线程的每次 sleep/wait 拉长; +`PONTE_TEST_THREAD_START_DELAY=0.15` 让刚 `start()` 的线程迟迟跑不到第一行。 +后者是前者够不到的:还没开始执行的线程没有任何等待可以被拉长——而它在空闲机器上 +永远通过、在忙机器上随机失败。两者共同的效果是:“只有机器够快才通过”的测试会 +**每次都**在那里失败,而不是偶发地红一次。怀疑是 runner 抽风之前,先这样在本地跑一遍: ```bash -PONTE_TEST_THREAD_DELAY=0.15 pytest # 模拟慢机器(Git Bash / POSIX 语法) +PONTE_TEST_THREAD_DELAY=0.15 PONTE_TEST_THREAD_START_DELAY=0.15 pytest ``` +如果你要写“等后台线程产出某件东西”的断言,请等截止时间(见 `tests/_waits.py`), +不要睡一个固定秒数;守卫任务存在的意义就是把这个差别从偶发红变成必然红。 + ## 项目结构 ``` diff --git a/README.md b/README.md index 2806cdb..ca309bb 100644 --- a/README.md +++ b/README.md @@ -324,14 +324,18 @@ python _smoke_test.py # zero-dependency quick check ``` CI runs lint + types on Linux, and the test suite across -Windows/Linux/macOS × Python 3.11/3.12, reporting coverage to +Windows/Linux/macOS × Python 3.11–3.14, reporting coverage to [Codecov](https://codecov.io/gh/modusensus/ponte). One extra job re-runs the -suite with `PONTE_TEST_THREAD_DELAY=0.15`: that injects latency into -worker-thread sleeps and waits, so a test that only passes on a fast machine -fails there *every* time instead of flaking once in a while. Set the same -variable locally to reproduce such a machine. A `build` job also installs -the built wheel and runs `ponte init`, so a packaging regression cannot ship -again. See [CONTRIBUTING.md](CONTRIBUTING.md). +suite with `PONTE_TEST_THREAD_DELAY=0.15` **and** +`PONTE_TEST_THREAD_START_DELAY=0.15`: the first stretches every worker-thread +sleep and wait, the second holds a freshly started thread before its first line +runs (a case no amount of wait-stretching can reach). A test that only passes on +a fast machine fails there *every* time instead of flaking once in a while. Set +the same variables locally to reproduce such a machine. Another job runs the +suite under a C locale (non-UTF-8 stdio) in a half-hour timezone with +deprecation warnings as errors, and a `build` job installs the built wheel and +runs `ponte init`, so a packaging regression cannot ship again. See +[CONTRIBUTING.md](CONTRIBUTING.md). ## 📝 Notes @@ -629,12 +633,14 @@ python _smoke_test.py # 零依赖快速自检 ``` CI 在 Linux 上跑 lint + 类型检查,在 Windows/Linux/macOS × Python -3.11/3.12 上跑测试,覆盖率上报到 -[Codecov](https://codecov.io/gh/modusensus/ponte)。另有一个任务会用 -`PONTE_TEST_THREAD_DELAY=0.15` 再跑一遍:它往工作线程的 sleep/wait 里注入 -延迟,于是"只有机器够快才通过"的测试会**每次都**在那里失败,而不是偶发地 -红一次。本地设同一个变量即可复现这种机器。`build` 任务会安装打好的 wheel 并 -执行 `ponte init`,避免打包问题再次溜进发布。详见 +3.11–3.14 上跑测试,覆盖率上报到 +[Codecov](https://codecov.io/gh/modusensus/ponte)。另有一个任务会同时用 +`PONTE_TEST_THREAD_DELAY=0.15` 与 `PONTE_TEST_THREAD_START_DELAY=0.15` 再跑 +一遍:前者把工作线程的每次 sleep/wait 拉长,后者让刚 start() 的线程迟迟跑不到 +第一行(后半种情况没有任何等待可以被拉长)。于是"只有机器够快才通过"的测试会 +**每次都**在那里失败,而不是偶发地红一次。本地设同样两个变量即可复现这种机器。 +还有一个任务在 C locale(非 UTF-8 的 stdio)、半时区偏移下跑,并把弃用告警当错误; +`build` 任务会安装打好的 wheel 并执行 `ponte init`,避免打包问题再次溜进发布。详见 [CONTRIBUTING.md](CONTRIBUTING.md)。 ## 📝 注意事项 diff --git a/tests/_injection.py b/tests/_injection.py new file mode 100644 index 0000000..ab41ee1 --- /dev/null +++ b/tests/_injection.py @@ -0,0 +1,177 @@ +"""把"慢机器"搬进测试进程的可选负载注入。 + +为什么需要它:依赖时序的断言只会**随机**报红。main 上真的红过一次——"睡 0.3 秒后至少 +3 次检查"拿到 2;而它既不是产品代码错,也不是 runner 抽风,而是**断言考的是"这台机器 +够快"**。快机器上它永远绿,慢机器上它偶尔红,两种结果都不回答"被测代码对不对"。 + +于是这里做的事是:在需要的时候,把"慢"变成一个**开关**,让那类测试当场失败。它属于 +测试基础设施而不是产品代码,但它也是唯一能被"证明"的部分——两条轴都有对应的自检 +(``tests/test_timing_guard.py``),因为一条静默失效的守卫比没有守卫更糟。 + +用法:由 ``tests/conftest.py`` 在会话开始时按环境变量装上(见 :func:`active`)。 +""" + +from __future__ import annotations + +import os +import threading +import time +from dataclasses import dataclass + +#: Seconds added to every *worker-thread* sleep/wait. +THREAD_DELAY_ENV = "PONTE_TEST_THREAD_DELAY" +#: Seconds a newly started thread waits *before running its body*. +START_DELAY_ENV = "PONTE_TEST_THREAD_START_DELAY" + +# The unpatched primitives, captured at import time: without these the injection +# would slow itself (and a thread start delay would be stretched by the wait +# delay, so the two axes would stop being independent). +_ORIGINAL_SLEEP = time.sleep +_ORIGINAL_WAIT = threading.Event.wait +_ORIGINAL_THREAD_START = threading.Thread.start + + +def _number_env(name: str) -> float: + """Read a numeric switch, refusing to silently ignore a broken value.""" + raw = os.environ.get(name, "").strip() + if not raw: + return 0.0 + try: + value = float(raw) + except ValueError: + raise SystemExit( + f"{name}={raw!r} is not a number. Refusing to continue: this switch " + "exists to make timing assumptions fail, so silently disabling it " + "would hide exactly what it guards." + ) from None + if value < 0: + raise SystemExit(f"{name} must not be negative: {raw!r}") + return value + + +@dataclass(frozen=True) +class Injection: + """The load this process is asked to emulate. Zero means "off".""" + + wait_delay: float = 0.0 + start_delay: float = 0.0 + + def enabled(self) -> bool: + return bool(self.wait_delay or self.start_delay) + + def banner(self) -> str: + """One line per enabled axis, so a green run can prove the guard was on.""" + lines = [] + if self.wait_delay: + lines.append( + f"thread latency: +{self.wait_delay:g}s injected into every worker sleep/wait" + ) + if self.start_delay: + lines.append( + f"thread start delay: +{self.start_delay:g}s before every thread body runs" + ) + return "\n".join(lines) + + +_INSTALLED: Injection | None = None + + +def active() -> Injection: + """The injection this process runs with, installing it on first call. + + 一次安装、幂等:``conftest`` 和 ``-p _injection``(守卫的自检会用子进程这么跑) + 可能先后触发,装上两次会把延迟叠成两倍,那时测量到的一切都不再可信。 + """ + global _INSTALLED + if _INSTALLED is None: + _INSTALLED = Injection(_number_env(THREAD_DELAY_ENV), _number_env(START_DELAY_ENV)) + if _INSTALLED.enabled(): + _apply(_INSTALLED) + return _INSTALLED + + +def pytest_configure(config) -> None: # noqa: ARG001 - 只为让 `-p _injection` 生效 + """Allow ``-p _injection`` to install the injection without a conftest.""" + active() + + +def _apply(injection: Injection) -> None: + """Make the code under test slower than the test that watches it. + + A slow machine fails timing-dependent tests in two distinct ways, and each + one needs its own instrument: + + **1. the worker's own waits are stretched** (``wait_delay``). "Slow machine" + is never uniform: every wait a *worker* performs gets queued behind whatever + else the runner is doing, while the test's own ``time.sleep(0.3)`` stays + exactly 0.3s. That asymmetry is what makes "slept 0.3s, expected 3 checks" + fail on a loaded macOS runner and pass here. So the injection only slows + threads that are not the main thread; stretching both sides equally would + preserve every ratio and prove nothing (the test's nap would grow to 0.9s + and the loop's ``wait(0.05)`` to 0.2s, still fitting six checks). + + **2. the worker does not get scheduled at all** (``start_delay``). This is + the axis waits cannot reach: a thread that has been started but has not run + its first bytecode yet performs *no* waits to stretch, so no amount of + ``wait_delay`` makes it late. A test that naps 50ms and then expects a + freshly started thread to have finished its work passes on an idle machine + and fails on a busy one — the "slept 0.05s for the stderr drain thread" shape + that ``tests/test_core.py`` had, and which the injection turned into a real + race in ``TunnelManager.connect`` (the drain thread read ``self.process``, + which the session's ``finally`` had already cleared). + + **...and deliberately no third axis for "the worker got no CPU at all".** + That was tried and measured — a busy Python thread competing for the GIL, + plus a duty-cycled variant — and it is both worse at finding bugs and far + more expensive. On this suite, one such thread turned pytest's *collection* + phase from 0.43s into 30s (two threads: 68s): GIL contention adds up to + ``sys.getswitchinterval()`` of latency to every reacquisition, and a suite + performs thousands of those. And it did not fail the very test this whole + mechanism exists for — a counter-scheduled worker still runs inside a 50ms + nap, because that nap releases the GIL. What a hog adds on top of the two + axes above is wall-clock cost, not coverage. The genuine "no spare CPU" + failure — a worker that never reaches its first bytecode in time — is axis 2. + + Two primitives cover how a background thread paces itself: ``Event.wait`` + and ``time.sleep``. Clocks (``time.monotonic``) are deliberately left alone — + moving those would corrupt deadlines instead of emulating load. A ``sleep(0)`` + is a yield rather than a wait, and load does not stretch it, so it stays. + + Scope, honestly: both axes emulate *a worker that is late*, which is the + failure mode behind every flake this exists for. What they cannot express is a + main-thread budget measured in work rather than in time — "this loop should + have run 10_000 times in 0.2s", which is the one thing the rejected hog above + *would* have caught, and only by an unpredictable factor. Don't read a green + run here as "no timing assumptions left". + """ + if injection.start_delay: + # Instance-level ``run`` override: the delay happens *inside* the new + # thread (the GIL is released during it, as when a ready thread waits for + # a core), which is precisely "started, but not yet running". + def slow_start(self: threading.Thread) -> None: + real_run = self.run + + def delayed_run() -> None: + _ORIGINAL_SLEEP(injection.start_delay) + real_run() + + self.run = delayed_run + _ORIGINAL_THREAD_START(self) + + threading.Thread.start = slow_start # type: ignore[method-assign] + + if injection.wait_delay: + main_thread = threading.main_thread() + + def slow_sleep(seconds: float) -> None: + if seconds > 0 and threading.current_thread() is not main_thread: + seconds += injection.wait_delay + _ORIGINAL_SLEEP(seconds) + + def slow_wait(event: threading.Event, timeout: float | None = None) -> bool: + if timeout is not None and threading.current_thread() is not main_thread: + timeout += injection.wait_delay + return _ORIGINAL_WAIT(event, timeout) + + time.sleep = slow_sleep + threading.Event.wait = slow_wait diff --git a/tests/conftest.py b/tests/conftest.py index 4ad4356..402ef48 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -5,95 +5,31 @@ next test, and ``get_config()`` could pick up the developer's real ``~/.config/ponte/config.toml``. -It also owns the optional *latency injection* that turns "this test only passes -on a fast machine" from a random CI failure into a deterministic one — see -:func:`_install_thread_delay` and ``PONTE_TEST_THREAD_DELAY``. +It also installs the optional *load injection* that turns "this test only passes +on a fast machine" from a random CI failure into a deterministic one. The +machinery lives in ``tests/_injection.py`` so that it can also be installed +without a conftest (the guard's own self-check runs it in a child process); this +file only decides when it happens — before any test module, so that no thread +created by a test module is left uninstrumented. """ from __future__ import annotations -import os -import threading -import time - import pytest +from _injection import active from ponte import config as config_module -#: Seconds added to every *worker-thread* sleep/wait. Unset or ``0`` disables the -#: injection entirely, so the normal suite is untouched. -_THREAD_DELAY_ENV = "PONTE_TEST_THREAD_DELAY" - - -def _thread_delay() -> float: - """Seconds to inject into worker-thread sleeps and waits (``0`` = off).""" - raw = os.environ.get(_THREAD_DELAY_ENV, "").strip() - if not raw: - return 0.0 - try: - delay = float(raw) - except ValueError: - raise SystemExit( - f"{_THREAD_DELAY_ENV}={raw!r} is not a number. Refusing to continue: " - "this switch exists to make timing assumptions fail, so silently " - "disabling it would hide exactly what it guards." - ) from None - if delay < 0: - raise SystemExit(f"{_THREAD_DELAY_ENV} must not be negative: {raw!r}") - return delay - - -def _install_thread_delay(delay: float) -> None: - """Make the code under test slower than the test that watches it. - - "Slow machine" is never uniform. Every wait and sleep a *worker* performs - gets queued behind whatever else the runner is doing, while the test's own - ``time.sleep(0.3)`` stays exactly 0.3s — that asymmetry is what makes - "slept 0.3s, expected 3 checks" fail on a loaded macOS runner and pass here. - So the injection only slows threads that are not the main thread; stretching - both sides equally would preserve every ratio and prove nothing (the test's - nap would grow to 0.9s and the loop's ``wait(0.05)`` to 0.2s, still fitting - six checks). - - Two primitives cover how a background thread paces itself: ``Event.wait`` - and ``time.sleep``. Clocks (``time.monotonic``) are deliberately left alone — - moving those would corrupt deadlines instead of emulating load. A ``sleep(0)`` - is a yield rather than a wait, and load does not stretch it, so it stays. - - Scope, honestly: this emulates *a worker that waits or is scheduled late*, - which is the failure mode behind the CI flake this exists for. It does not - emulate *a worker starved of CPU* — a test that naps on the main thread while - a worker does real work is untouched by it and still relies on the runner - being fast. Don't read a green run here as "no timing assumptions left". - """ - main_thread = threading.main_thread() - real_sleep = time.sleep - real_wait = threading.Event.wait - - def slow_sleep(seconds: float) -> None: - if seconds > 0 and threading.current_thread() is not main_thread: - seconds += delay - real_sleep(seconds) - - def slow_wait(event: threading.Event, timeout: float | None = None) -> bool: - if timeout is not None and threading.current_thread() is not main_thread: - timeout += delay - return real_wait(event, timeout) - - time.sleep = slow_sleep - threading.Event.wait = slow_wait - - -_DELAY = _thread_delay() -if _DELAY: - _install_thread_delay(_DELAY) +#: What this session was asked to emulate; installing is idempotent, so this is +#: the one place the environment switches are read for the whole session. +_INJECTION = active() def pytest_report_header() -> str: """Show where the config layer resolves to, which explains most failures.""" header = "ponte config search path: " + " | ".join(config_module.config_search_paths()) - if _DELAY: - header += f"\nthread latency: +{_DELAY:g}s injected into every worker sleep/wait" + if _INJECTION.enabled(): + header += "\n" + _INJECTION.banner() return header diff --git a/tests/test_timing_guard.py b/tests/test_timing_guard.py index 23be2c8..d8d0059 100644 --- a/tests/test_timing_guard.py +++ b/tests/test_timing_guard.py @@ -1,24 +1,65 @@ -"""Guards for the latency injection itself (``PONTE_TEST_THREAD_DELAY``). +"""Guards for the load injection itself (``tests/_injection.py``). -一个静默失效的守卫比没有守卫更糟:它会把"慢 runner"那条 CI 腿变成一场空跑,而 -输出仍是绿的。所以这里直接测量机制,而不是相信开关的名字。 +一条静默失效的守卫比没有守卫更糟:它会把"慢 runner"那条 CI 腿变成一场空跑,而输出 +仍是绿的。所以这里做两件事,而不是相信开关的名字: + +1. 直接**测量机制**——工作线程真的被拖慢了、主线程没有; +2. 用子进程跑一条**故意依赖时序的探针测试**,证明注入确实把它从绿变成红。第 2 条是 + 整个机制的核心承诺,只有它做得到"证明",前一条只是"测量"。 """ from __future__ import annotations import os +import subprocess import sys import threading import time +from pathlib import Path import pytest -#: Mirrors ``tests/conftest.py``; read from the environment so this file does not -#: depend on how pytest happens to name the conftest module. -_DELAY = float(os.environ.get("PONTE_TEST_THREAD_DELAY", "0") or 0) +from _injection import START_DELAY_ENV, THREAD_DELAY_ENV, active + +_INJECTION = active() _PROBE_WAIT = 0.01 +#: 子进程探针的固定睡眠与注入的启动延迟。取值刻意比 CI 用的 0.15s 夸张:这条自检必须 +#: 在任何机器上都确定性地翻红,包括空闲的开发机——它证明的是机制,不是 CI 的取值。 +_PROBE_NAP = "0.3" +_PROBE_START_DELAY = "1.0" + +#: 探针就是"主线程睡一个固定秒数,然后假设刚起的工作线程已经跑过"——本仓库真的这么 +#: 写过(``tests/test_core.py`` 里"给 drain 线程 50ms")。用 ``-c`` 而不是落盘文件: +#: 子进程的启动成本要压在零点几秒,否则这条自检本身就成了套件里最慢的东西。 +#: +#: 它的报错文本故意用 ASCII:子进程继承套件当时的环境,而在非 UTF-8 的机器上(CI 真 +#: 有这种腿,见 ci.yml),一句中文连 stderr 都写不出去——那时这个自检自己就成了它想 +#: 找的那类环境依赖。(不是猜测:本仓就是在 ``PYTHONIOENCODING=ascii`` 下把这条测试 +#: 弄红过。) +_NAP_PROBE = ''' +import os +import threading +import time + +import _injection + +_injection.active() # 子进程自己装上负载注入,按环境变量决定装什么 + +seen = [] + + +def worker(): + seen.append(1) + + +threading.Thread(target=worker, daemon=True).start() +time.sleep(float(os.environ["PROBE_NAP"])) +if not seen: + raise SystemExit("worker did not run within the fixed nap") +''' + def _wait_in_worker() -> float: """Seconds a *worker* thread actually spends in ``Event.wait(0.01)``.""" @@ -36,11 +77,22 @@ def worker() -> None: return elapsed[0] +def _start_latency() -> float: + """从 ``Thread.start()`` 返回,到线程体的第一行被执行,隔了多久。""" + began: list[float] = [] + thread = threading.Thread(target=lambda: began.append(time.monotonic()), daemon=True) + started = time.monotonic() + thread.start() + thread.join(timeout=5) + assert began, "worker thread never ran its body" + return began[0] - started + + def test_injection_slows_workers_only_when_the_switch_is_on() -> None: """开着时工作线程变慢、主线程不变;关着时两者都不受影响。 主线程这一半是重点:把测试自己的 ``time.sleep`` 也拉长会保持所有比例, - 于是它测不出任何东西(见 conftest 里的说明)。 + 于是它测不出任何东西(见 ``_injection`` 里的说明)。 """ started = time.monotonic() threading.Event().wait(_PROBE_WAIT) @@ -48,14 +100,23 @@ def test_injection_slows_workers_only_when_the_switch_is_on() -> None: worker_elapsed = _wait_in_worker() # `is` 而不是 `==`:开关是"开/关"两种情形,不是一条连续刻度。 - if _DELAY: - assert worker_elapsed >= _PROBE_WAIT + _DELAY * 0.8, worker_elapsed - assert main_elapsed < _PROBE_WAIT + _DELAY * 0.5, main_elapsed + if _INJECTION.wait_delay: + assert worker_elapsed >= _PROBE_WAIT + _INJECTION.wait_delay * 0.8, worker_elapsed + assert main_elapsed < _PROBE_WAIT + _INJECTION.wait_delay * 0.5, main_elapsed else: assert worker_elapsed < _PROBE_WAIT + 0.25, worker_elapsed assert main_elapsed < _PROBE_WAIT + 0.25, main_elapsed +def test_start_delay_holds_a_new_thread_before_its_body_runs() -> None: + """第二条轴:线程已经被 start()、但还没跑第一行——等待被拉长管不到这种情况。""" + latency = _start_latency() + if _INJECTION.start_delay: + assert latency >= _INJECTION.start_delay * 0.8, latency + else: + assert latency < 0.25, latency + + def _conftest_header() -> str: """The header our own conftest contributes, via the module pytest loaded.""" # 不调 pytestconfig.hook:那个钩子是 firstresult,返回的是**别的插件**的结果; @@ -75,7 +136,46 @@ def test_injection_is_announced_in_the_report_header() -> None: 这条横幅也是 CI 那一步能自检的依据(job 会 grep 它,见 ci.yml)。 """ header = _conftest_header() - if _DELAY: - assert f"thread latency: +{_DELAY:g}s" in header, header + if _INJECTION.enabled(): + assert _INJECTION.banner() in header, header else: assert "thread latency" not in header, header + assert "thread start delay" not in header, header + + +def _run_nap_probe(*, start_delay: str) -> subprocess.CompletedProcess: + """Run the nap-based probe in a child process, with *start_delay* injected.""" + env = os.environ.copy() + # 子进程自己跑解释器:把父进程的 coverage / 当前测试状态摘掉,免得互相污染。 + for name in ( + "COV_CORE_SOURCE", + "COV_CORE_CONFIG", + "COV_CORE_DATAFILE", + "PYTEST_CURRENT_TEST", + ): + env.pop(name, None) + env.pop(THREAD_DELAY_ENV, None) # 这条自检只启用第二条轴,证明它单独就够用 + env[START_DELAY_ENV] = start_delay + env["PROBE_NAP"] = _PROBE_NAP + tests_dir = str(Path(__file__).parent) + env["PYTHONPATH"] = tests_dir + os.pathsep + env.get("PYTHONPATH", "") + return subprocess.run( + [sys.executable, "-c", _NAP_PROBE], + capture_output=True, + text=True, + env=env, + timeout=120, + ) + + +def test_injection_turns_a_timing_dependent_test_from_green_to_red() -> None: + """守卫的核心承诺,两个方向都要看到:注入开启时探针必须红,关闭时必须绿。 + + 只验"开着时红"是不够的——一个把**所有**东西都弄红的坏注入同样满足它。 + """ + injected = _run_nap_probe(start_delay=_PROBE_START_DELAY) + assert injected.returncode != 0, injected.stdout + injected.stderr + assert "worker did not run within the fixed nap" in injected.stderr, injected.stderr + + clean = _run_nap_probe(start_delay="0") + assert clean.returncode == 0, clean.stdout + clean.stderr From edd163d49e5e8c626146cc7c1d059977eeeee447 Mon Sep 17 00:00:00 2001 From: modusensus Date: Sun, 20 Sep 2026 13:02:11 +0800 Subject: [PATCH 4/4] =?UTF-8?q?test:=20=E6=8E=A2=E9=92=88=E6=BA=90?= =?UTF-8?q?=E7=A0=81=E4=BF=9D=E6=8C=81=E7=BA=AF=20ASCII=E2=80=94=E2=80=94C?= =?UTF-8?q?=20locale=20=E4=B8=8B=E9=9D=9E=20ASCII=20=E8=BF=9E=20argv=20?= =?UTF-8?q?=E9=83=BD=E4=BC=A0=E4=B8=8D=E8=BF=9B=E5=AD=90=E8=BF=9B=E7=A8=8B?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 新的 env-edges 腿在 CI 上抓到这条自检自己: os.posix_spawn(...) → UnicodeEncodeError: 'ascii' codec can't encode characters in position 83-104 那 22 个字符正是探针里的一句中文注释。C locale 下文件系统编码就是 ASCII,所以 - 中文写不进 stderr(本地就撞过:PYTHONIOENCODING=ascii 下这条测试直接红); - 作为 `-c` 的参数更彻底:argv 根本进不了子进程。 改成全 ASCII 并把原因写进注释——不然下一个人会把它当成风格问题改回去。这不是“猜到的 风险”:两条都是真实运行出来的,且报的是同一个位置。 🤖 Generated with Codebuff Co-Authored-By: Codebuff --- tests/test_timing_guard.py | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/tests/test_timing_guard.py b/tests/test_timing_guard.py index d8d0059..e1be461 100644 --- a/tests/test_timing_guard.py +++ b/tests/test_timing_guard.py @@ -34,10 +34,11 @@ #: 写过(``tests/test_core.py`` 里"给 drain 线程 50ms")。用 ``-c`` 而不是落盘文件: #: 子进程的启动成本要压在零点几秒,否则这条自检本身就成了套件里最慢的东西。 #: -#: 它的报错文本故意用 ASCII:子进程继承套件当时的环境,而在非 UTF-8 的机器上(CI 真 -#: 有这种腿,见 ci.yml),一句中文连 stderr 都写不出去——那时这个自检自己就成了它想 -#: 找的那类环境依赖。(不是猜测:本仓就是在 ``PYTHONIOENCODING=ascii`` 下把这条测试 -#: 弄红过。) +#: 里面的字符**全部是 ASCII**(包括注释),这不是风格问题,是被 CI 实测出来的:非 UTF-8 +#: 的机器上(C locale 腿,见 ci.yml)文件系统编码就是 ASCII,中文连 stderr 都写不出去, +#: 而作为 ``-c`` 的参数更直接——前一句注释曾让 ``os.posix_spawn`` 抛 +#: ``UnicodeEncodeError: 'ascii' codec ...``:**argv 根本传不进去**。那时这个自检自己就 +#: 成了它想找的那类环境依赖。 _NAP_PROBE = ''' import os import threading @@ -45,7 +46,7 @@ import _injection -_injection.active() # 子进程自己装上负载注入,按环境变量决定装什么 +_injection.active() # install the injection from this child's environment seen = []