From 4cb7abc3aca001e69f65ef9775f237775f24495c Mon Sep 17 00:00:00 2001 From: Krzysztof kuhy Rudnicki Date: Sat, 22 Aug 2026 21:06:06 +0200 Subject: [PATCH] vmbox: fix the boot deadlock that made every sealed image unreachable Root cause, confirmed causally rather than inferred: masking systemd-timesyncd (which vmbox does so `-rtc base=` stays pinned, since timesyncd otherwise resets the guest clock to real time) left systemd-time-wait-sync waiting for a sync that can never arrive. That unit sat in "start running" forever and every other job queued behind it as "start waiting" -- sshd included -- so the guest never reached multi-user.target. It booted to a login prompt and looked perfectly healthy while being permanently unreachable. The fix is one line: mask both units together. Four earlier hypotheses were each disproven by measurement. What finally worked was asking the guest instead of reading absence-of-log-lines: `systemctl is-system-running` returned "starting", and `systemctl list-jobs` put systemd-time-wait-sync at the head of the queue. Stopping it made sshd active and bound :22 within seconds, and ssh from the host then succeeded. Rule for next time: a unit that is enabled, has satisfied dependencies, and neither starts nor fails is QUEUED -- check list-jobs first. The smoke gate added earlier did its job here: it caught the unreachable image and refused to seal it, keeping the sandbox so its logs survived. Also fixes serial_exec markers to be plain alphanumerics -- shell metacharacters get echoed and line-wrapped by the tty, which made them unreliable to match and produced spurious timeouts. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01VdyMBGCrGVGDWtJ9xe48f3 --- vmbox/guest/provision.sh | 7 +++++++ vmbox/lib/serial_exec.py | 38 +++++++++++++++++++++++++++++++++----- 2 files changed, 40 insertions(+), 5 deletions(-) diff --git a/vmbox/guest/provision.sh b/vmbox/guest/provision.sh index 10e70fb..0a3611d 100644 --- a/vmbox/guest/provision.sh +++ b/vmbox/guest/provision.sh @@ -186,6 +186,13 @@ systemctl enable systemd-networkd systemd-resolved 2>/dev/null || true # re-introduces exactly the nondeterminism -rtc exists to remove. systemctl disable systemd-timesyncd 2>/dev/null || true systemctl mask systemd-timesyncd 2>/dev/null || true +# CRITICAL: systemd-time-wait-sync waits for a sync that can never arrive once +# timesyncd is masked. It then sits in "start running" forever and every other +# job -- sshd included -- queues behind it as "start waiting", so the system +# never reaches multi-user.target. The guest boots to a login prompt and looks +# healthy while being permanently unreachable. Mask it together with timesyncd. +systemctl disable systemd-time-wait-sync 2>/dev/null || true +systemctl mask systemd-time-wait-sync 2>/dev/null || true # Do NOT write a /etc/systemd/network/*.network file here: an en* match # also catches the primary NIC and outranks the cloud image's own DHCP # config, which breaks sshd's network and makes the sandbox unreachable. diff --git a/vmbox/lib/serial_exec.py b/vmbox/lib/serial_exec.py index c61636f..7ec521a 100755 --- a/vmbox/lib/serial_exec.py +++ b/vmbox/lib/serial_exec.py @@ -70,18 +70,46 @@ class Console: self.sock.sendall(b"\n") return self.read_until(PROMPT, timeout) + def read_until_count(self, needle: str, count: int, timeout: float) -> bool: + """Wait until `needle` has been seen `count` times. + + A tty echoes what you type, so the marker appears once in the echoed + command line before it ever appears in real output. Waiting for the + first occurrence returns immediately -- before the command has run -- + and yields an empty or truncated result that looks like a hang. + """ + end = time.time() + timeout + while time.time() < end: + if clean(self.buf).count(needle) >= count: + return True + try: + chunk = self.sock.recv(4096) + except TimeoutError: + continue + except OSError: + return False + if not chunk: + return False + self.buf += chunk + return clean(self.buf).count(needle) >= count + def run(self, cmd: str, timeout: float = 300) -> str: - token = uuid.uuid4().hex[:8] - start, done = f"<<>>", f"<<>>" + # Markers are plain alphanumerics: shell metacharacters like < and > + # are echoed back by the tty and can be reordered or line-wrapped, + # which makes them unreliable to match on. + token = uuid.uuid4().hex[:8].upper() + start, done = f"VMBOXS{token}", f"VMBOXE{token}" self.buf = b"" # `; echo RC=$?` keeps the guest's exit status, which the ssh path # cannot report once the machine stops. self.sock.sendall(f"echo {start}; {cmd}; echo RC=$?; echo {done}\n".encode()) - if not self.read_until(done, timeout): + # Twice: once in the echoed command line, once in real output. + if not self.read_until_count(done, 2, timeout): return f"### TIMEOUT: no end marker after {timeout}s ###" text = clean(self.buf) - body = text.split(start, 1)[-1].split(done, 1)[0] - # Drop the echoed command line itself. + # Take the LAST start marker and the text up to the following end + # marker: everything before that is the echo of what we typed. + body = text.rsplit(start, 1)[-1].split(done, 1)[0] lines = [ln for ln in body.splitlines() if start not in ln and done not in ln] return "\n".join(lines).strip()