test(xceadmin): capture live HA E2E stderr instead of DEVNULL (bug-1485 investigation)
bug-1485 (flaky test_live_config_push_against_primary_reaches_success_path, ~24/25 fail rate under pytest, primary process going <defunct> after promotion) could never be diagnosed because controller stderr was DEVNULL'd -- no ASAN report or signal was ever captured from a real failure. Redirects each node's stderr to deploy_dir/logs/<name>.stderr.log and adds an XCE_KEEP_DEPLOY_DIR=1 debug toggle to preserve the deploy dir across fixture cleanup for inspection. Ran the live test 40 times in this environment (25 idle + 15 under concurrent build contention): 40/40 passed, 0/120 captured stderr logs non-empty -- could not reproduce. Downgraded to low-priority/environment-flake, left open; the capture infrastructure stays in place for the next real failure. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LXkenK8rqE8mdS1YKjsq78
This commit is contained in:
parent
8e75b0c10c
commit
a5560256ea
1 changed files with 71 additions and 2 deletions
|
|
@ -126,10 +126,60 @@ boot, not a new one) closes that window: a still-flapping port keeps
|
||||||
retrying inside ``wait_for_port`` instead of racing straight into the
|
retrying inside ``wait_for_port`` instead of racing straight into the
|
||||||
push and surfacing as a confusing ``ConnectionRefusedError``/``ETIMEDOUT``
|
push and surfacing as a confusing ``ConnectionRefusedError``/``ETIMEDOUT``
|
||||||
deep inside the test body.
|
deep inside the test body.
|
||||||
|
|
||||||
|
bug-1485 investigation (2026-08-01): round-2's own remediation above (this
|
||||||
|
file's current state) was subsequently found flaky again -- ~24/25 failures
|
||||||
|
over ~25 live pytest-invoked runs, timing out in a fresh ``wait_for_port``
|
||||||
|
re-probe of the elected primary even after both election markers and the
|
||||||
|
settle window succeeded, because the freshly-elected primary process itself
|
||||||
|
went ``<defunct>`` shortly after logging its own promotion -- but only under
|
||||||
|
pytest's process tree; byte-identical standalone (non-pytest) repro scripts
|
||||||
|
never reproduced it. stderr was DEVNULL'd at the time, so no ASAN report or
|
||||||
|
signal was ever captured from a real failure (see buglog bug-1485's own
|
||||||
|
"next step": capture stderr instead of DEVNULL and re-attempt).
|
||||||
|
|
||||||
|
This session redirected each node's stderr to
|
||||||
|
``deploy_dir/logs/<name>.stderr.log`` (permanent change, below) and re-ran
|
||||||
|
the live test 25 times in this environment (an otherwise-idle sandbox,
|
||||||
|
load average ~2 on 22 cores, no concurrent builds/soaks) with
|
||||||
|
``XCE_KEEP_DEPLOY_DIR=1`` to preserve every run's artifacts: 25/25 passed,
|
||||||
|
and all 75 captured stderr logs (3 nodes x 25 runs) were empty -- no crash,
|
||||||
|
no ASAN report, in any run. The flake could NOT be reproduced here despite
|
||||||
|
matching the documented repro shape exactly (same binaries, same fixture,
|
||||||
|
same pytest invocation). Given bug-1486 (logged the same day, 2026-07-31:
|
||||||
|
concurrent `xce-build.sh` sessions on a shared sandbox clobbering each
|
||||||
|
other's build dir) already demonstrates this sandbox sees genuine
|
||||||
|
cross-session interference under concurrent load, the leading hypothesis is
|
||||||
|
that the original ~24/25 failure rate was itself a symptom of resource
|
||||||
|
contention from other concurrent sessions on the same machine during that
|
||||||
|
investigation (CPU starvation delaying the primary's post-election
|
||||||
|
warmup past ``_POST_ELECTION_SETTLE_S``, or an OOM-adjacent condition
|
||||||
|
killing the freshly-forked primary outright) rather than a bug in the
|
||||||
|
promotion path reachable in isolation -- consistent with "genuinely
|
||||||
|
timing-sensitive... pytest's process tree somehow makes far more likely"
|
||||||
|
from the original investigation, since pytest's own subprocess tree adds
|
||||||
|
real memory/fd overhead a bare ``python3`` repro script does not carry.
|
||||||
|
NOT closing bug-1485 on this evidence alone (absence of reproduction is not
|
||||||
|
proof of absence of bug) -- downgrading to low-priority/environment-flake.
|
||||||
|
|
||||||
|
Follow-up same session: ran the contention hypothesis directly -- 15 more
|
||||||
|
live attempts with a concurrent `xce-build.sh controller debug` compile
|
||||||
|
racing for CPU (a separate build.dbg dir, so it could not clobber the
|
||||||
|
xce.build controller binary this test depends on, unlike bug-1486's own
|
||||||
|
same-dir clobber shape). Also 15/15 passed, all 45 more stderr logs empty.
|
||||||
|
A single concurrent compile is not proof against the contention hypothesis
|
||||||
|
(the real multi-session sandbox reality bug-1486 documents involves several
|
||||||
|
concurrent AGENT SESSIONS, each potentially running its own live 3-node
|
||||||
|
soak/E2E cluster, not just one background compile) -- but it is one more
|
||||||
|
data point against it. Total this session: 40/40 passed, 0/120 stderr logs
|
||||||
|
non-empty. Left as an open, low-priority, currently-unreproducible flake;
|
||||||
|
the stderr-capture infrastructure below is now in place for the next person
|
||||||
|
who hits it live to actually get a diagnostic instead of DEVNULL silence.
|
||||||
"""
|
"""
|
||||||
|
|
||||||
from __future__ import annotations
|
from __future__ import annotations
|
||||||
|
|
||||||
|
import os
|
||||||
import re
|
import re
|
||||||
import shutil
|
import shutil
|
||||||
import subprocess
|
import subprocess
|
||||||
|
|
@ -273,9 +323,19 @@ def live_ha_cluster(tmp_path: Path):
|
||||||
|
|
||||||
procs: list[subprocess.Popen] = []
|
procs: list[subprocess.Popen] = []
|
||||||
nodes: list[HaNode] = []
|
nodes: list[HaNode] = []
|
||||||
|
stderr_files: list = []
|
||||||
try:
|
try:
|
||||||
for i, (name, addr) in enumerate(zip(names, addrs)):
|
for i, (name, addr) in enumerate(zip(names, addrs)):
|
||||||
log_file = deploy_dir / "logs" / f"{name}.log"
|
log_file = deploy_dir / "logs" / f"{name}.log"
|
||||||
|
# bug-1485 investigation (2026-08-01): capture stderr to a real
|
||||||
|
# file instead of DEVNULL so a crash (ASAN report, signal) is
|
||||||
|
# visible instead of silently discarded -- the prior DEVNULL
|
||||||
|
# redirect was the reason no diagnostic was ever captured from a
|
||||||
|
# real pytest-triggered failure (see this file's own docstring /
|
||||||
|
# buglog bug-1485's "next step").
|
||||||
|
stderr_path = deploy_dir / "logs" / f"{name}.stderr.log"
|
||||||
|
stderr_f = open(stderr_path, "wb")
|
||||||
|
stderr_files.append(stderr_f)
|
||||||
proc = subprocess.Popen(
|
proc = subprocess.Popen(
|
||||||
[
|
[
|
||||||
str(controller_bin),
|
str(controller_bin),
|
||||||
|
|
@ -287,7 +347,7 @@ def live_ha_cluster(tmp_path: Path):
|
||||||
"--vcpus", "4",
|
"--vcpus", "4",
|
||||||
],
|
],
|
||||||
stdout=subprocess.DEVNULL,
|
stdout=subprocess.DEVNULL,
|
||||||
stderr=subprocess.DEVNULL,
|
stderr=stderr_f,
|
||||||
)
|
)
|
||||||
procs.append(proc)
|
procs.append(proc)
|
||||||
nodes.append(HaNode(name=name, addr=addr, log_file=log_file))
|
nodes.append(HaNode(name=name, addr=addr, log_file=log_file))
|
||||||
|
|
@ -321,7 +381,16 @@ def live_ha_cluster(tmp_path: Path):
|
||||||
except subprocess.TimeoutExpired:
|
except subprocess.TimeoutExpired:
|
||||||
proc.kill()
|
proc.kill()
|
||||||
proc.wait(timeout=10)
|
proc.wait(timeout=10)
|
||||||
shutil.rmtree(deploy_dir, ignore_errors=True)
|
for f in stderr_files:
|
||||||
|
f.close()
|
||||||
|
# bug-1485 investigation (2026-08-01): XCE_KEEP_DEPLOY_DIR lets a
|
||||||
|
# manual repro run inspect deploy_dir/logs/*.stderr.log after a
|
||||||
|
# failure instead of it being deleted unconditionally here on every
|
||||||
|
# run (pass or fail). Debug-only -- unset in normal test runs.
|
||||||
|
if not os.environ.get("XCE_KEEP_DEPLOY_DIR"):
|
||||||
|
shutil.rmtree(deploy_dir, ignore_errors=True)
|
||||||
|
else:
|
||||||
|
print(f"XCE_KEEP_DEPLOY_DIR set -- preserved {deploy_dir}")
|
||||||
|
|
||||||
|
|
||||||
def _build_cluster_bin(xceadmin_bin: Path, tmp_path: Path) -> Path:
|
def _build_cluster_bin(xceadmin_bin: Path, tmp_path: Path) -> Path:
|
||||||
|
|
|
||||||
Loading…
Add table
Add a link
Reference in a new issue